[keycloak-user] Two OIDC working, but not SSO

Tech tech at psynd.net
Tue Apr 25 08:18:01 EDT 2017


Anybody with any ideas?





On 25/04/17 12:53, Tech wrote:
>
> Hello Marek,
>
> maybe my email was confusing, we run initially two tests were we login 
> and logout in both portal to check that the oidc is working on each of 
> them.
>
> Once we know that OIDC is working, then we are expecting to login to 
> portal1 and opening portal2, to find us already logged in, but this 
> doesn't happen and we are forced to login again
>
>
>
>
> On 25/04/17 12:41, Marek Posolda wrote:
>> If you don't do "Logout from portal1" at the end of first test, then 
>> SSO should work and you will be automatically logged into portal2 
>> without a need to put your credentials.
>>
>> The logout is "SSO logout", hence it also kills the SSO session on 
>> Keycloak side and requires user to re-login.
>>
>> Marek
>>
>> On 25/04/17 12:31, Tech wrote:
>>> Dear experts,
>>>
>>> we are working with Moodle, a PHP based platform, where we have been
>>> able to configure correctly Keycloak to implement OIDC.
>>>
>>> To test Keycloak we cloned this application, with different URLs and we
>>> did the first test:
>>>
>>>    * Connect to portal1
>>>    * User not recognized and redirected to Keycloak through OIDC
>>>    * Enter credentials stored into Keycloak
>>>    * User accepted and redirected to portal1
>>>    * Logout from portal1
>>>
>>> After this we tested the second application:
>>>
>>>    * Connect to portal2
>>>    * User not recognized and redirected to Keycloak through OIDC
>>>    * Enter credentials stored into Keycloak
>>>    * User accepted and redirected to portal2
>>>    * Logout from portal2
>>>
>>> In this case I know that OIDC is working for the two applications 
>>> and we
>>> can expect that also the SSO is working, but after the login in portal1
>>> we have to login again portal2, and vice-versa.
>>>
>>> We attach below here some logs, could you please help?
>>>
>>> Thanks
>>>
>>>
>>>
>>>
>>>
>>> *Login to portal1*
>>>
>>> 2017-04-25 09:54:40,503 DEBUG [org.jboss.ejb.client.txn] (Periodic
>>> Recovery) Send recover request for transaction origin node identifier 1
>>> to EJB receiver with node name 79051ccf69ac
>>> 2017-04-25 09:54:45,055 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-30) new
>>> JtaTransactionWrapper
>>> 2017-04-25 09:54:45,056 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-30) was
>>> existing? false
>>> 2017-04-25 09:54:45,056 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
>>> (default task-30) RESTEASY002315: PathInfo:
>>> /realms/demo/protocol/openid-connect/auth
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.AuthenticationProcessor] (default task-30)
>>> AUTHENTICATE
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.AuthenticationProcessor] (default task-30)
>>> AUTHENTICATE ONLY
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) processFlow
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) check execution: auth-cookie requirement: ALTERNATIVE
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) authenticator: auth-cookie
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) invoke authenticator.authenticate
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.services.managers.AuthenticationManager] (default 
>>> task-30)
>>> Could not find cookie: KEYCLOAK_IDENTITY
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) authenticator ATTEMPTED: auth-cookie
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) check execution: auth-spnego requirement: DISABLED
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) execution is processed
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) check execution: identity-provider-redirector requirement:
>>> ALTERNATIVE
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) authenticator: identity-provider-redirector
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) invoke authenticator.authenticate
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) authenticator ATTEMPTED: identity-provider-redirector
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) check execution: null requirement: ALTERNATIVE
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) execution is flow
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) processFlow
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) check execution: auth-username-password-form requirement: 
>>> REQUIRED
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) authenticator: auth-username-password-form
>>> 2017-04-25 09:54:45,059 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) invoke authenticator.authenticate
>>> 2017-04-25 09:54:45,060 DEBUG [freemarker.cache] (default task-30)
>>> TemplateLoader.findTemplateSource("template_en_US.ftl"): Not found
>>> 2017-04-25 09:54:45,060 DEBUG [freemarker.cache] (default task-30)
>>> TemplateLoader.findTemplateSource("template_en.ftl"): Not found
>>> 2017-04-25 09:54:45,060 DEBUG [freemarker.cache] (default task-30)
>>> TemplateLoader.findTemplateSource("template.ftl"): Found
>>> 2017-04-25 09:54:45,061 DEBUG [freemarker.cache] (default task-30)
>>> "template.ftl"("en_US", UTF-8, parsed): using cached since
>>> file:/opt/jboss/keycloak/themes/base/login/template.ftl hasn't changed.
>>> 2017-04-25 09:54:45,064 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-30) authenticator CHALLENGE: auth-username-password-form
>>> 2017-04-25 09:54:45,064 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-30)
>>> JtaTransactionWrapper  commit
>>> 2017-04-25 09:54:45,064 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-30)
>>> JtaTransactionWrapper end
>>> 2017-04-25 09:54:50,503 DEBUG [org.jboss.ejb.client.txn] (Periodic
>>> Recovery) Send recover request for transaction origin node identifier 1
>>> to EJB receiver with node name 79051ccf69ac
>>>
>>>
>>>
>>>
>>> *After authentication to portal1**
>>> *
>>> 2017-04-25 09:54:56,041 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-31) new
>>> JtaTransactionWrapper
>>> 2017-04-25 09:54:56,041 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-31) was
>>> existing? false
>>> 2017-04-25 09:54:56,042 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
>>> (default task-31) RESTEASY002315: PathInfo:
>>> /realms/Demo/login-actions/authenticate
>>> 2017-04-25 09:54:56,042 DEBUG
>>> [org.keycloak.authentication.AuthenticationProcessor] (default task-31)
>>> authenticationAction
>>> 2017-04-25 09:54:56,042 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) processAction: dfde24fe-5e06-4dc9-8dc2-f82eedd89846
>>> 2017-04-25 09:54:56,043 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) check: auth-cookie requirement: ALTERNATIVE
>>> 2017-04-25 09:54:56,043 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) execution is processed
>>> 2017-04-25 09:54:56,043 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) check: auth-spnego requirement: DISABLED
>>> 2017-04-25 09:54:56,043 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) execution is processed
>>> 2017-04-25 09:54:56,043 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) check: identity-provider-redirector requirement: ALTERNATIVE
>>> 2017-04-25 09:54:56,043 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) execution is processed
>>> 2017-04-25 09:54:56,043 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) check: null requirement: ALTERNATIVE
>>> 2017-04-25 09:54:56,043 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) processAction: dfde24fe-5e06-4dc9-8dc2-f82eedd89846
>>> 2017-04-25 09:54:56,043 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) check: auth-username-password-form requirement: REQUIRED
>>> 2017-04-25 09:54:56,043 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) action: auth-username-password-form
>>> 2017-04-25 09:54:56,141 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) authenticator SUCCESS: auth-username-password-form
>>> 2017-04-25 09:54:56,141 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) processFlow
>>> 2017-04-25 09:54:56,141 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) check execution: auth-otp-form requirement: OPTIONAL
>>> 2017-04-25 09:54:56,141 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) authenticator: auth-otp-form
>>> 2017-04-25 09:54:56,141 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default
>>> task-31) processFlow
>>> 2017-04-25 09:54:56,141 DEBUG
>>> [org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl] 
>>>
>>> (default task-31) Hibernate RegisteredSynchronization successfully
>>> registered with JTA platform
>>> 2017-04-25 09:54:56,142 DEBUG [org.hibernate.SQL] (default task-31)
>>>       select
>>>           roleentity0_.ID as col_0_0_
>>>       from
>>>           KEYCLOAK_ROLE roleentity0_
>>>       where
>>>           roleentity0_.CLIENT_ROLE=0
>>>           and roleentity0_.NAME=?
>>>           and roleentity0_.REALM=?
>>> 2017-04-25 09:54:56,142 DEBUG
>>> [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (default
>>> task-31) MySqlDS: getConnection(null,
>>> WrappedConnectionRequestInfo at 4570d800[userName=KeycloakUSR]) [0/20]
>>> 2017-04-25 09:54:56,143 DEBUG
>>> [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl]
>>> (default task-31) Initiating JDBC connection release from 
>>> afterStatement
>>> 2017-04-25 09:54:56,143 DEBUG [org.hibernate.SQL] (default task-31)
>>>       select
>>>           roleentity0_.ID as col_0_0_
>>>       from
>>>           KEYCLOAK_ROLE roleentity0_
>>>       where
>>>           roleentity0_.CLIENT_ROLE=0
>>>           and roleentity0_.NAME=?
>>>           and roleentity0_.REALM=?
>>> 2017-04-25 09:54:56,144 DEBUG
>>> [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl]
>>> (default task-31) Initiating JDBC connection release from 
>>> afterStatement
>>> 2017-04-25 09:54:56,144 DEBUG [org.hibernate.SQL] (default task-31)
>>>       select
>>>           roleentity0_.ID as col_0_0_
>>>       from
>>>           KEYCLOAK_ROLE roleentity0_
>>>       where
>>>           roleentity0_.CLIENT_ROLE=0
>>>           and roleentity0_.NAME=?
>>>           and roleentity0_.REALM=?
>>> 2017-04-25 09:54:56,144 DEBUG
>>> [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl]
>>> (default task-31) Initiating JDBC connection release from 
>>> afterStatement
>>> 2017-04-25 09:54:56,145 DEBUG [org.keycloak.events] (default task-31)
>>> type=LOGIN, realmId=Demo, clientId=moodle,
>>> userId=ed5ba52a-531d-4e6e-b12e-9bc0957a8c1f, ipAddress=192.168.0.27,
>>> auth_method=openid-connect, auth_type=code,
>>> redirect_uri=https://localhost/moodleiam/auth/oidc/,
>>> consent=no_consent_required,
>>> code_id=08539f13-cb1c-423e-86a3-365c29b055f1, username=testuser
>>> 2017-04-25 09:54:56,145 DEBUG
>>> [org.keycloak.services.managers.AuthenticationManager] (default 
>>> task-31)
>>> Removing old user session: session: 
>>> 9a5218f8-aa9c-496c-aa00-780430f19c1b
>>> 2017-04-25 09:54:56,145 DEBUG
>>> [org.keycloak.services.managers.AuthenticationManager] (default 
>>> task-31)
>>> Create login cookie - name: KEYCLOAK_IDENTITY, path: /auth/realms/Demo,
>>> max-age: -1
>>> 2017-04-25 09:54:56,145 DEBUG
>>> [org.keycloak.services.managers.AuthenticationManager] (default 
>>> task-31)
>>> Expiring remember me cookie
>>> 2017-04-25 09:54:56,145 DEBUG
>>> [org.keycloak.services.managers.AuthenticationManager] (default 
>>> task-31)
>>> Expiring cookie: KEYCLOAK_REMEMBER_ME path: /auth/realms/Demo
>>> 2017-04-25 09:54:56,146 DEBUG
>>> [org.keycloak.protocol.oidc.OIDCLoginProtocol] (default task-31)
>>> redirectAccessCode: state: bIJNAcPb8Rxz8Wb
>>> 2017-04-25 09:54:56,146 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-31)
>>> JtaTransactionWrapper  commit
>>> 2017-04-25 09:54:56,149 DEBUG
>>> [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (default
>>> task-31) MySqlDS: returnConnection(4edba62b, false) [0/20]
>>> 2017-04-25 09:54:56,149 DEBUG
>>> [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl]
>>> (default task-31) Initiating JDBC connection release from 
>>> afterTransaction
>>> 2017-04-25 09:54:56,149 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-31)
>>> JtaTransactionWrapper end
>>> 2017-04-25 09:54:56,642 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-24) new
>>> JtaTransactionWrapper
>>> 2017-04-25 09:54:56,642 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-24) was
>>> existing? false
>>> 2017-04-25 09:54:56,642 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
>>> (default task-24) RESTEASY002315: PathInfo:
>>> /realms/demo/protocol/openid-connect/token
>>> 2017-04-25 09:54:56,643 DEBUG
>>> [org.keycloak.authentication.AuthenticationProcessor] (default task-24)
>>> AUTHENTICATE CLIENT
>>> 2017-04-25 09:54:56,643 DEBUG
>>> [org.keycloak.authentication.ClientAuthenticationFlow] (default 
>>> task-24)
>>> client authenticator: client-secret
>>> 2017-04-25 09:54:56,643 DEBUG
>>> [org.keycloak.authentication.ClientAuthenticationFlow] (default 
>>> task-24)
>>> client authenticator SUCCESS: client-secret
>>> 2017-04-25 09:54:56,643 DEBUG
>>> [org.keycloak.authentication.ClientAuthenticationFlow] (default 
>>> task-24)
>>> Client moodle authenticated by client-secret
>>> 2017-04-25 09:54:56,663 DEBUG [org.keycloak.events] (default task-24)
>>> type=CODE_TO_TOKEN, realmId=Demo, clientId=moodle,
>>> userId=ed5ba52a-531d-4e6e-b12e-9bc0957a8c1f, ipAddress=153.109.152.213,
>>> token_id=75173922-dd56-44ca-9255-9a5368e557f4,
>>> grant_type=authorization_code, refresh_token_type=Refresh,
>>> refresh_token_id=d7daabe5-8e73-4b8e-b108-92188e1118df,
>>> code_id=08539f13-cb1c-423e-86a3-365c29b055f1,
>>> client_auth_method=client-secret
>>> 2017-04-25 09:54:56,663 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-24)
>>> JtaTransactionWrapper  commit
>>> 2017-04-25 09:54:56,663 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-24)
>>> JtaTransactionWrapper end
>>>
>>>
>>>
>>>
>>> *Login to portal2**
>>> *
>>> 2017-04-25 09:56:17,566 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-6) new
>>> JtaTransactionWrapper
>>> 2017-04-25 09:56:17,566 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-6) was
>>> existing? false
>>> 2017-04-25 09:56:17,567 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
>>> (default task-6) RESTEASY002315: PathInfo:
>>> /realms/demo/protocol/openid-connect/auth
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.AuthenticationProcessor] (default task-6)
>>> AUTHENTICATE
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.AuthenticationProcessor] (default task-6)
>>> AUTHENTICATE ONLY
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> processFlow
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> check execution: auth-cookie requirement: ALTERNATIVE
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> authenticator: auth-cookie
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> invoke authenticator.authenticate
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.services.managers.AuthenticationManager] (default task-6)
>>> Could not find cookie: KEYCLOAK_IDENTITY
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> authenticator ATTEMPTED: auth-cookie
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> check execution: auth-spnego requirement: DISABLED
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> execution is processed
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> check execution: identity-provider-redirector requirement: ALTERNATIVE
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> authenticator: identity-provider-redirector
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> invoke authenticator.authenticate
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> authenticator ATTEMPTED: identity-provider-redirector
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> check execution: null requirement: ALTERNATIVE
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> execution is flow
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> processFlow
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> check execution: auth-username-password-form requirement: REQUIRED
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> authenticator: auth-username-password-form
>>> 2017-04-25 09:56:17,569 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> invoke authenticator.authenticate
>>> 2017-04-25 09:56:17,572 DEBUG [freemarker.cache] (default task-6)
>>> TemplateLoader.findTemplateSource("template_en_US.ftl"): Not found
>>> 2017-04-25 09:56:17,572 DEBUG [freemarker.cache] (default task-6)
>>> TemplateLoader.findTemplateSource("template_en.ftl"): Not found
>>> 2017-04-25 09:56:17,572 DEBUG [freemarker.cache] (default task-6)
>>> TemplateLoader.findTemplateSource("template.ftl"): Found
>>> 2017-04-25 09:56:17,572 DEBUG [freemarker.cache] (default task-6)
>>> "template.ftl"("en_US", UTF-8, parsed): using cached since
>>> file:/opt/jboss/keycloak/themes/base/login/template.ftl hasn't changed.
>>> 2017-04-25 09:56:17,573 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-6)
>>> authenticator CHALLENGE: auth-username-password-form
>>> 2017-04-25 09:56:17,573 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-6)
>>> JtaTransactionWrapper  commit
>>> 2017-04-25 09:56:17,573 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-6)
>>> JtaTransactionWrapper end
>>>
>>>
>>>
>>>
>>> *After authentication to portal2**
>>> *
>>> 2017-04-25 09:56:29,001 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-4) new
>>> JtaTransactionWrapper
>>> 2017-04-25 09:56:29,001 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-4) was
>>> existing? false
>>> 2017-04-25 09:56:29,001 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
>>> (default task-4) RESTEASY002315: PathInfo:
>>> /realms/Demo/login-actions/authenticate
>>> 2017-04-25 09:56:29,002 DEBUG
>>> [org.keycloak.authentication.AuthenticationProcessor] (default task-4)
>>> authenticationAction
>>> 2017-04-25 09:56:29,002 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> processAction: dfde24fe-5e06-4dc9-8dc2-f82eedd89846
>>> 2017-04-25 09:56:29,002 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> check: auth-cookie requirement: ALTERNATIVE
>>> 2017-04-25 09:56:29,002 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> execution is processed
>>> 2017-04-25 09:56:29,002 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> check: auth-spnego requirement: DISABLED
>>> 2017-04-25 09:56:29,002 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> execution is processed
>>> 2017-04-25 09:56:29,004 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> check: identity-provider-redirector requirement: ALTERNATIVE
>>> 2017-04-25 09:56:29,004 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> execution is processed
>>> 2017-04-25 09:56:29,004 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> check: null requirement: ALTERNATIVE
>>> 2017-04-25 09:56:29,004 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> processAction: dfde24fe-5e06-4dc9-8dc2-f82eedd89846
>>> 2017-04-25 09:56:29,004 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> check: auth-username-password-form requirement: REQUIRED
>>> 2017-04-25 09:56:29,004 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> action: auth-username-password-form
>>> 2017-04-25 09:56:29,099 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> authenticator SUCCESS: auth-username-password-form
>>> 2017-04-25 09:56:29,100 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> processFlow
>>> 2017-04-25 09:56:29,100 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> check execution: auth-otp-form requirement: OPTIONAL
>>> 2017-04-25 09:56:29,100 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> authenticator: auth-otp-form
>>> 2017-04-25 09:56:29,100 DEBUG
>>> [org.keycloak.authentication.DefaultAuthenticationFlow] (default 
>>> task-4)
>>> processFlow
>>> 2017-04-25 09:56:29,100 DEBUG
>>> [org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl] 
>>>
>>> (default task-4) Hibernate RegisteredSynchronization successfully
>>> registered with JTA platform
>>> 2017-04-25 09:56:29,100 DEBUG [org.hibernate.SQL] (default task-4)
>>>       select
>>>           roleentity0_.ID as col_0_0_
>>>       from
>>>           KEYCLOAK_ROLE roleentity0_
>>>       where
>>>           roleentity0_.CLIENT_ROLE=0
>>>           and roleentity0_.NAME=?
>>>           and roleentity0_.REALM=?
>>> 2017-04-25 09:56:29,101 DEBUG
>>> [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (default
>>> task-4) MySqlDS: getConnection(null,
>>> WrappedConnectionRequestInfo at 4570d800[userName=KeycloakUSR]) [0/20]
>>> 2017-04-25 09:56:29,102 DEBUG
>>> [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl]
>>> (default task-4) Initiating JDBC connection release from afterStatement
>>> 2017-04-25 09:56:29,103 DEBUG [org.hibernate.SQL] (default task-4)
>>>       select
>>>           roleentity0_.ID as col_0_0_
>>>       from
>>>           KEYCLOAK_ROLE roleentity0_
>>>       where
>>>           roleentity0_.CLIENT_ROLE=0
>>>           and roleentity0_.NAME=?
>>>           and roleentity0_.REALM=?
>>> 2017-04-25 09:56:29,103 DEBUG
>>> [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl]
>>> (default task-4) Initiating JDBC connection release from afterStatement
>>> 2017-04-25 09:56:29,103 DEBUG [org.hibernate.SQL] (default task-4)
>>>       select
>>>           roleentity0_.ID as col_0_0_
>>>       from
>>>           KEYCLOAK_ROLE roleentity0_
>>>       where
>>>           roleentity0_.CLIENT_ROLE=0
>>>           and roleentity0_.NAME=?
>>>           and roleentity0_.REALM=?
>>> 2017-04-25 09:56:29,104 DEBUG
>>> [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl]
>>> (default task-4) Initiating JDBC connection release from afterStatement
>>> 2017-04-25 09:56:29,104 DEBUG [org.keycloak.events] (default task-4)
>>> type=LOGIN, realmId=Demo, clientId=moodle2,
>>> userId=ed5ba52a-531d-4e6e-b12e-9bc0957a8c1f, ipAddress=192.168.0.27,
>>> auth_method=openid-connect, auth_type=code,
>>> redirect_uri=https://localhost/moodle2iam/auth/oidc/,
>>> consent=no_consent_required,
>>> code_id=cffeac69-54fc-4d19-be81-36f0f19ce1ef, username=testuser
>>> 2017-04-25 09:56:29,104 DEBUG
>>> [org.keycloak.services.managers.AuthenticationManager] (default task-4)
>>> Removing old user session: session: 
>>> 431cecf6-5a6b-4bbc-9467-3f52eff8090f
>>> 2017-04-25 09:56:29,105 DEBUG
>>> [org.keycloak.services.managers.AuthenticationManager] (default task-4)
>>> Create login cookie - name: KEYCLOAK_IDENTITY, path: /auth/realms/Demo,
>>> max-age: -1
>>> 2017-04-25 09:56:29,105 DEBUG
>>> [org.keycloak.services.managers.AuthenticationManager] (default task-4)
>>> Expiring remember me cookie
>>> 2017-04-25 09:56:29,105 DEBUG
>>> [org.keycloak.services.managers.AuthenticationManager] (default task-4)
>>> Expiring cookie: KEYCLOAK_REMEMBER_ME path: /auth/realms/Demo
>>> 2017-04-25 09:56:29,105 DEBUG
>>> [org.keycloak.protocol.oidc.OIDCLoginProtocol] (default task-4)
>>> redirectAccessCode: state: WUCTMXokISFDbFN
>>> 2017-04-25 09:56:29,105 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-4)
>>> JtaTransactionWrapper  commit
>>> 2017-04-25 09:56:29,106 DEBUG
>>> [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (default
>>> task-4) MySqlDS: returnConnection(4edba62b, false) [0/20]
>>> 2017-04-25 09:56:29,106 DEBUG
>>> [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl]
>>> (default task-4) Initiating JDBC connection release from 
>>> afterTransaction
>>> 2017-04-25 09:56:29,106 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-4)
>>> JtaTransactionWrapper end
>>> 2017-04-25 09:56:29,626 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-13) new
>>> JtaTransactionWrapper
>>> 2017-04-25 09:56:29,626 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-13) was
>>> existing? false
>>> 2017-04-25 09:56:29,627 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
>>> (default task-13) RESTEASY002315: PathInfo:
>>> /realms/demo/protocol/openid-connect/token
>>> 2017-04-25 09:56:29,627 DEBUG
>>> [org.keycloak.authentication.AuthenticationProcessor] (default task-13)
>>> AUTHENTICATE CLIENT
>>> 2017-04-25 09:56:29,627 DEBUG
>>> [org.keycloak.authentication.ClientAuthenticationFlow] (default 
>>> task-13)
>>> client authenticator: client-secret
>>> 2017-04-25 09:56:29,627 DEBUG
>>> [org.keycloak.authentication.ClientAuthenticationFlow] (default 
>>> task-13)
>>> client authenticator SUCCESS: client-secret
>>> 2017-04-25 09:56:29,627 DEBUG
>>> [org.keycloak.authentication.ClientAuthenticationFlow] (default 
>>> task-13)
>>> Client moodle2 authenticated by client-secret
>>> 2017-04-25 09:56:29,656 DEBUG [org.keycloak.events] (default task-13)
>>> type=CODE_TO_TOKEN, realmId=Demo, clientId=moodle2,
>>> userId=ed5ba52a-531d-4e6e-b12e-9bc0957a8c1f, ipAddress=153.109.152.213,
>>> token_id=ff9b3385-1362-4559-ad53-05317755b280,
>>> grant_type=authorization_code, refresh_token_type=Refresh,
>>> refresh_token_id=356011d7-e9fa-4c90-9368-a7627a445bc7,
>>> code_id=cffeac69-54fc-4d19-be81-36f0f19ce1ef,
>>> client_auth_method=client-secret
>>> 2017-04-25 09:56:29,656 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-13)
>>> JtaTransactionWrapper  commit
>>> 2017-04-25 09:56:29,656 DEBUG
>>> [org.keycloak.transaction.JtaTransactionWrapper] (default task-13)
>>> JtaTransactionWrapper end
>>> 2017-04-25 09:56:29,660 DEBUG [io.undertow.request.io] (default I/O-1)
>>> Error reading request: java.io.IOException: Connection reset by peer
>>>           at sun.nio.ch.FileDispatcherImpl.read0(Native Method)
>>>           at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)
>>>           at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)
>>>           at sun.nio.ch.IOUtil.read(IOUtil.java:192)
>>>           at 
>>> sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:380)
>>>           at 
>>> org.xnio.nio.NioSocketConduit.read(NioSocketConduit.java:282)
>>>           at
>>> io.undertow.protocols.ssl.SslConduit.doUnwrap(SslConduit.java:658)
>>>           at 
>>> io.undertow.protocols.ssl.SslConduit.read(SslConduit.java:530)
>>>           at
>>> org.xnio.conduits.ConduitStreamSourceChannel.read(ConduitStreamSourceChannel.java:127) 
>>>
>>>           at
>>> io.undertow.server.protocol.http.HttpReadListener.handleEventWithNoRunningRequest(HttpReadListener.java:152) 
>>>
>>>           at
>>> io.undertow.server.protocol.http.HttpReadListener.handleEvent(HttpReadListener.java:130) 
>>>
>>>           at
>>> io.undertow.server.protocol.http.HttpReadListener.handleEvent(HttpReadListener.java:56) 
>>>
>>>           at
>>> org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92) 
>>>
>>>           at
>>> org.xnio.conduits.ReadReadyHandler$ChannelListenerHandler.readReady(ReadReadyHandler.java:66) 
>>>
>>>           at
>>> io.undertow.protocols.ssl.SslConduit$SslReadReadyHandler.readReady(SslConduit.java:1059) 
>>>
>>>           at
>>> org.xnio.nio.NioSocketConduit.handleReady(NioSocketConduit.java:88)
>>>           at org.xnio.nio.WorkerThread.run(WorkerThread.java:559)
>>>
>>> _______________________________________________
>>> keycloak-user mailing list
>>> keycloak-user at lists.jboss.org
>>> https://lists.jboss.org/mailman/listinfo/keycloak-user
>>
>>
>



More information about the keycloak-user mailing list