I try to test a very simple SAML login flow with:
- docker container Tomcat 8.5-jre8
- docker container keycloak 15
I successfully managed to log a test user in but whenever i try to access a simple JSP page
https://<APP-HOSTNAME>/index.jsp
(which is in a security-constraint in the tomcat web.xml configuration) with only “helloworld” text (no java, js, … code) I’m always getting redirected to:
https://<KEYCLOAK-HOSTNAME>/auth/realms/master/login-actions/authenticate?client_id=SamlTest01&tab_id=RA2e0obwX8k
that give me the message:
Keycloak
You are already logged in.
and not showing me the expected JSP page.
WHAT I’M GETTING WRONG?
My Tomcat configuration are:
- context.xml
<?xml version="1.0" encoding="UTF-8"?>
<Context path="/">
<Valve className="org.keycloak.adapters.saml.tomcat.SamlAuthenticatorValve"/>
</Context>
- web.xml
<?xml version="1.0" encoding="ISO-8859-1"?>
<web-app xmlns="http://java.sun.com/xml/ns/javaee" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/web-app_3_0.xsd"
version="3.0">
<module-name>sales-post-enc</module-name>
<!-- Define a Security Constraint on this Application, only index.jsp and piechart.gif. The rest is needed for logout.jsp -->
<security-constraint>
<web-resource-collection>
<web-resource-name>INDEX page</web-resource-name>
<url-pattern>/index.jsp</url-pattern>
</web-resource-collection>
<auth-constraint>
<role-name>manager</role-name>
</auth-constraint>
</security-constraint>
<!-- Define the Login Configuration for this Application -->
<login-config>
<auth-method>KEYCLOAK-SAML</auth-method>
</login-config>
<!-- Security roles referenced by this web application -->
<security-role>
<description>The role that is required to log in to the Manager Application</description>
<role-name>manager</role-name>
</security-role>
<security-role>
<role-name>user</role-name>
</security-role>
</web-app>
- keycloak_saml.xml
<keycloak-saml-adapter>
<SP entityID="SamlTest01"
sslPolicy="EXTERNAL"
logoutPage="/logout.jsp">
<Keys>
<Key signing="true">
<PrivateKeyPem>
...
</PrivateKeyPem>
<CertificatePem>
....
</CertificatePem>
</Key>
</Keys>
<IDP entityID="idp"
signatureAlgorithm="RSA_SHA256"
signatureCanonicalizationMethod="http://www.w3.org/2001/10/xml-exc-c14n#">
<SingleSignOnService signRequest="true"
validateResponseSignature="true"
validateAssertionSignature="false"
requestBinding="POST"
bindingUrl="https://<KEYCLOAK-HOSTNAME>/auth/realms/master/protocol/saml"/>
<SingleLogoutService signRequest="true"
signResponse="true"
validateRequestSignature="true"
validateResponseSignature="true"
requestBinding="POST"
responseBinding="POST"
postBindingUrl="https://<KEYCLOAK-HOSTNAME>/auth/realms/master/protocol/saml"
redirectBindingUrl="https://<KEYCLOAK-HOSTNAME>/auth/realms/master/protocol/saml"/>
</IDP>
</SP>
</keycloak-saml-adapter>
My Keycloak Client configuration is:
{
"clientId": "SamlTest01",
"name": "SamlTest01",
"rootUrl": "https://<APPLICATION-HOSTNAME>/index.jsp",
"adminUrl": "",
"baseUrl": "",
"surrogateAuthRequired": false,
"enabled": true,
"alwaysDisplayInConsole": true,
"clientAuthenticatorType": "client-secret",
"redirectUris": [
"*"
],
"webOrigins": [],
"notBefore": 0,
"bearerOnly": false,
"consentRequired": false,
"standardFlowEnabled": true,
"implicitFlowEnabled": false,
"directAccessGrantsEnabled": false,
"serviceAccountsEnabled": false,
"publicClient": false,
"frontchannelLogout": false,
"protocol": "saml",
"attributes": {
"saml.force.post.binding": "true",
"saml.multivalued.roles": "false",
"oauth2.device.authorization.grant.enabled": "false",
"backchannel.logout.revoke.offline.tokens": "false",
"saml.server.signature.keyinfo.ext": "false",
"use.refresh.tokens": "true",
"saml.signing.certificate": "....",
"oidc.ciba.grant.enabled": "false",
"backchannel.logout.session.required": "false",
"client_credentials.use_refresh_token": "false",
"saml.signature.algorithm": "RSA_SHA256",
"require.pushed.authorization.requests": "false",
"saml.client.signature": "false",
"saml.signing.private.key": "....",
"saml.server.signature.keyinfo.xmlSigKeyInfoKeyNameTransformer": "KEY_ID",
"id.token.as.detached.signature": "false",
"saml.assertion.signature": "false",
"saml.encrypt": "false",
"login_theme": "base",
"saml.server.signature": "false",
"exclude.session.state.from.auth.response": "false",
"saml.artifact.binding.identifier": "fD/Tabif5BL0FjYRSX8J+vUujTg=",
"saml.artifact.binding": "false",
"saml_force_name_id_format": "false",
"tls.client.certificate.bound.access.tokens": "false",
"saml.authnstatement": "false",
"display.on.consent.screen": "false",
"saml.assertion.lifespan": "600",
"saml_name_id_format": "username",
"saml.onetimeuse.condition": "false",
"saml_signature_canonicalization_method": "http://www.w3.org/2001/10/xml-exc-c14n#"
},
"authenticationFlowBindingOverrides": {
"browser": "b8133cf5-8a14-4d9a-a75f-eeff5ebffb45"
},
"fullScopeAllowed": true,
"nodeReRegistrationTimeout": -1,
"defaultClientScopes": [
"role_list"
],
"optionalClientScopes": [],
"access": {
"view": true,
"configure": true,
"manage": true
}
}
The docker keycloak logs are:
keycloak_1 | 11:34:42,399 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) new JtaTransactionWrapper
keycloak_1 | 11:34:42,399 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) was existing? false
keycloak_1 | 11:34:42,399 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) JtaTransactionWrapper commit
keycloak_1 | 11:34:42,399 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) JtaTransactionWrapper end
keycloak_1 | 11:34:42,399 DEBUG [org.keycloak.services.scheduled.ScheduledTaskRunner] (Timer-2) Executed scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$1902/0x0000000841662c40
keycloak_1 | 11:34:42,837 DEBUG [io.undertow.request] (default I/O-7) Matched prefix path /auth for path /auth/realms/master/protocol/saml
keycloak_1 | 11:34:42,837 DEBUG [io.undertow.request.security] (default task-22) Attempting to authenticate /auth/realms/master/protocol/saml, authentication required: false
keycloak_1 | 11:34:42,837 DEBUG [io.undertow.request.security] (default task-22) Authentication outcome was NOT_ATTEMPTED with method io.undertow.security.impl.CachedAuthenticatedSessionMechanism@2862f3b6 for /auth/realms/master/protocol/saml
keycloak_1 | 11:34:42,838 DEBUG [io.undertow.request.security] (default task-22) Authentication result was ATTEMPTED for /auth/realms/master/protocol/saml
keycloak_1 | 11:34:42,838 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (default task-22) new JtaTransactionWrapper
keycloak_1 | 11:34:42,838 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (default task-22) was existing? false
keycloak_1 | 11:34:42,838 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) RESTEASY002315: PathInfo: /realms/master/protocol/saml
keycloak_1 | 11:34:42,839 DEBUG [org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl] (default task-22) Hibernate RegisteredSynchronization successfully registered with JTA platform
keycloak_1 | 11:34:42,840 DEBUG [org.keycloak.protocol.saml.SamlService] (default task-22) SAML POST
keycloak_1 | 11:34:42,840 DEBUG [org.keycloak.saml.SAMLRequestParser] (default task-22) SAML POST Binding
keycloak_1 | 11:34:42,840 DEBUG [org.keycloak.saml.SAMLRequestParser] (default task-22) <samlp:AuthnRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" xmlns="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion" Destination="https://<KEYCLOAK-HOSTNAME>/auth/realms/master/protocol/saml" ForceAuthn="false" ID="ID_3bb8b3b7-a269-4b5b-9ae3-161660867eb0" IssueInstant="2021-09-10T11:34:42.721Z" Version="2.0"><saml:Issuer>SamlTest01</saml:Issuer><dsig:Signature xmlns:dsig="http://www.w3.org/2000/09/xmldsig#"><dsig:SignedInfo><dsig:CanonicalizationMethod Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/><dsig:SignatureMethod Algorithm="http://www.w3.org/2001/04/xmldsig-more#rsa-sha256"/><dsig:Reference URI="#ID_3bb8b3b7-a269-4b5b-9ae3-161660867eb0"><dsig:Transforms><dsig:Transform Algorithm="http://www.w3.org/2000/09/xmldsig#enveloped-signature"/><dsig:Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/></dsig:Transforms><dsig:DigestMethod Algorithm="http://www.w3.org/2001/04/xmlenc#sha256"/><dsig:DigestValue>dCM5QYuj6zed+jvgsEun+TdbHjRXHB8uD3fNQ31d8SQ=</dsig:DigestValue></dsig:Reference></dsig:SignedInfo><dsig:SignatureValue>QQjX8j/DbYhc9wkJ8WUyRWjfMva1B7tjVIASI2vd8SryDU9A+ApO5U1RKHJAeK03LKlUsj6wNnoyUxGQcJehjSV5jT136x4Wi62Iz6ZB0qYnraVCOXSciPRLh/OXRRV6yp3aEV+MSSrtchD1x03wN82D3oFhiuVKI9CwcknnTgzAivwQP6xHhMaYRUH6ZiO4RgsvsnLuplD+oHJOCRVmwxZuaQ8Eoqag2F6clSL+HAUE0yj1AB7SBrvROHBKr7PMIN/eDZ7GyFWbR4mm67Gijg0+syrftK4YAqXmJTS4N1CLj+cYLLccRQ0zyvC+6hiMPmI930YKQ8qH0e8UvZtnMQ==</dsig:SignatureValue><dsig:KeyInfo><dsig:KeyValue><dsig:RSAKeyValue><dsig:Modulus>m77TwopfOJO5lw676PI8/1gK5ZKl5ekbyd7Xe5IY5tRbC6RF6KHTLMrvyK2R3KypRGVNp2aXgNkUlw8saPIs2gMzYX4kHmTRFyVtyr3PcEGuxdRe7e2mNGirOsX7rNFlvHnENTV5YP7GraOgX8hdvsPQFI6ZjranSVHlr2qz0XWEDNgh1tOIQmRJrzzwerLE9mLS6qjZVkeM++wyHAGQ3Kgq+No/O1Kmd6C34vTAiCV9267T225UmC2SEe5V1GIz57nIj1l2PkhwyP4qw5YLI4ixXYMqxBoSCbEAdgX4syiI5qim+pj/1wOURnIjw6Emj9/O1o7GAyFAK8uTmD74Sw==</dsig:Modulus><dsig:Exponent>AQAB</dsig:Exponent></dsig:RSAKeyValue></dsig:KeyValue></dsig:KeyInfo></dsig:Signature><samlp:NameIDPolicy AllowCreate="true" Format="urn:oasis:names:tc:SAML:2.0:nameid-format:persistent"/></samlp:AuthnRequest>
keycloak_1 | 11:34:42,841 DEBUG [org.keycloak.protocol.saml.SamlService] (default task-22) ** login request
keycloak_1 | 11:34:42,841 DEBUG [org.keycloak.protocol.saml.SamlService] (default task-22) verified request
keycloak_1 | 11:34:42,842 DEBUG [org.keycloak.services.util.CookieHelper] (default task-22) AUTH_SESSION_ID cookie found in the request header
keycloak_1 | 11:34:42,842 DEBUG [org.keycloak.services.util.CookieHelper] (default task-22) AUTH_SESSION_ID cookie found in the cookie field
keycloak_1 | 11:34:42,842 DEBUG [org.keycloak.services.managers.AuthenticationSessionManager] (default task-22) Found AUTH_SESSION_ID cookie with value e628f22a-abd5-4d18-87eb-faffa4d5dc51.4cabab710c64
keycloak_1 | 11:34:42,842 DEBUG [org.keycloak.services.util.CookieHelper] (default task-22) AUTH_SESSION_ID cookie found in the request header
keycloak_1 | 11:34:42,843 DEBUG [org.keycloak.services.util.CookieHelper] (default task-22) AUTH_SESSION_ID cookie found in the cookie field
keycloak_1 | 11:34:42,843 DEBUG [org.keycloak.services.managers.AuthenticationSessionManager] (default task-22) Found AUTH_SESSION_ID cookie with value e628f22a-abd5-4d18-87eb-faffa4d5dc51.4cabab710c64
keycloak_1 | 11:34:42,843 DEBUG [org.keycloak.models.sessions.infinispan.InfinispanUserSessionProvider] (default task-22) getUserSessionWithPredicate(e628f22a-abd5-4d18-87eb-faffa4d5dc51): remote cache not available
keycloak_1 | 11:34:42,844 DEBUG [org.keycloak.protocol.AuthorizationEndpointBase] (default task-22) Sent request to authz endpoint. We don't have root authentication session with ID 'e628f22a-abd5-4d18-87eb-faffa4d5dc51' but we have userSession.Re-created root authentication session with same ID. Client is: SamlTest01 . New authentication session tab ID: rVV5HB4YJss
keycloak_1 | 11:34:42,845 DEBUG [org.keycloak.authentication.AuthenticationProcessor] (default task-22) Redirecting to URL: https://<KEYCLOAK-HOSTNAME>/auth/realms/master/login-actions/authenticate?client_id=SamlTest01&tab_id=rVV5HB4YJss
keycloak_1 | 11:34:42,845 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (default task-22) JtaTransactionWrapper commit
keycloak_1 | 11:34:42,845 DEBUG [org.hibernate.engine.transaction.internal.TransactionImpl] (default task-22) On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
keycloak_1 | 11:34:42,845 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (default task-22) Initiating JDBC connection release from afterTransaction
keycloak_1 | 11:34:42,846 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (default task-22) JtaTransactionWrapper end
keycloak_1 | 11:34:42,846 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) RESTEASY009525: onComplete
keycloak_1 | 11:34:42,923 DEBUG [io.undertow.request] (default I/O-7) Matched prefix path /auth for path /auth/realms/master/login-actions/authenticate
keycloak_1 | 11:34:42,924 DEBUG [io.undertow.request.security] (default task-22) Attempting to authenticate /auth/realms/master/login-actions/authenticate, authentication required: false
keycloak_1 | 11:34:42,924 DEBUG [io.undertow.request.security] (default task-22) Authentication outcome was NOT_ATTEMPTED with method io.undertow.security.impl.CachedAuthenticatedSessionMechanism@2862f3b6 for /auth/realms/master/login-actions/authenticate
keycloak_1 | 11:34:42,924 DEBUG [io.undertow.request.security] (default task-22) Authentication result was ATTEMPTED for /auth/realms/master/login-actions/authenticate
keycloak_1 | 11:34:42,924 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (default task-22) new JtaTransactionWrapper
keycloak_1 | 11:34:42,924 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (default task-22) was existing? false
keycloak_1 | 11:34:42,924 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) RESTEASY002315: PathInfo: /realms/master/login-actions/authenticate
keycloak_1 | 11:34:42,925 DEBUG [org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl] (default task-22) Hibernate RegisteredSynchronization successfully registered with JTA platform
keycloak_1 | 11:34:42,925 DEBUG [org.keycloak.services.resources.SessionCodeChecks] (default task-22) Will use client 'SamlTest01' in back-to-application link
keycloak_1 | 11:34:42,925 DEBUG [org.keycloak.services.util.CookieHelper] (default task-22) AUTH_SESSION_ID cookie found in the request header
keycloak_1 | 11:34:42,925 DEBUG [org.keycloak.services.util.CookieHelper] (default task-22) AUTH_SESSION_ID cookie found in the cookie field
keycloak_1 | 11:34:42,926 DEBUG [org.keycloak.services.managers.AuthenticationSessionManager] (default task-22) Found AUTH_SESSION_ID cookie with value e628f22a-abd5-4d18-87eb-faffa4d5dc51.4cabab710c64
keycloak_1 | 11:34:42,926 DEBUG [org.keycloak.authentication.AuthenticationProcessor] (default task-22) AUTHENTICATE
keycloak_1 | 11:34:42,926 DEBUG [org.keycloak.authentication.AuthenticationProcessor] (default task-22) AUTHENTICATE ONLY
keycloak_1 | 11:34:42,926 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (default task-22) processFlow: browser
keycloak_1 | 11:34:42,926 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (default task-22) check execution: 'auth-cookie', requirement: 'ALTERNATIVE'
keycloak_1 | 11:34:42,926 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (default task-22) authenticator: auth-cookie
keycloak_1 | 11:34:42,926 DEBUG [org.keycloak.authentication.AuthenticationSelectionResolver] (default task-22) Going through the flow 'browser' for adding executions
keycloak_1 | 11:34:42,927 DEBUG [org.keycloak.authentication.AuthenticationSelectionResolver] (default task-22) Going through the flow 'forms' for adding executions
keycloak_1 | 11:34:42,927 DEBUG [org.keycloak.authentication.AuthenticationSelectionResolver] (default task-22) Selections when trying execution 'auth-cookie' : [ authSelection - auth-cookie, authSelection - identity-provider-redirector, authSelection - auth-username-password-form]
keycloak_1 | 11:34:42,927 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (default task-22) invoke authenticator.authenticate: auth-cookie
keycloak_1 | 11:34:42,927 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (default task-22) authenticator SUCCESS: auth-cookie
keycloak_1 | 11:34:42,928 DEBUG [org.keycloak.services.managers.AuthenticationSessionManager] (default task-22) Removing authSession 'e628f22a-abd5-4d18-87eb-faffa4d5dc51'. Expire restart cookie: true
keycloak_1 | 11:34:42,928 DEBUG [org.hibernate.event.internal.AbstractSaveEventListener] (default task-22) Generated identifier: 9556f19b-7824-425a-bcce-b7a04215b6fe, using strategy: org.hibernate.id.Assigned
keycloak_1 | 11:34:42,929 DEBUG [org.keycloak.services.managers.AuthenticationManager] (default task-22) Create login cookie - name: KEYCLOAK_IDENTITY, path: /auth/realms/master/, max-age: -1
keycloak_1 | 11:34:42,929 DEBUG [org.keycloak.services.managers.AuthenticationManager] (default task-22) Expiring remember me cookie
keycloak_1 | 11:34:42,929 DEBUG [org.keycloak.services.managers.AuthenticationManager] (default task-22) Expiring cookie: KEYCLOAK_REMEMBER_ME path: /auth/realms/master/
keycloak_1 | 11:34:42,930 DEBUG [org.hibernate.SQL] (default task-22)
keycloak_1 | select
keycloak_1 | clientscop0_.ID as ID1_12_0_,
keycloak_1 | clientscop0_.DESCRIPTION as DESCRIPT2_12_0_,
keycloak_1 | clientscop0_.NAME as NAME3_12_0_,
keycloak_1 | clientscop0_.PROTOCOL as PROTOCOL4_12_0_,
keycloak_1 | clientscop0_.REALM_ID as REALM_ID5_12_0_
keycloak_1 | from
keycloak_1 | CLIENT_SCOPE clientscop0_
keycloak_1 | where
keycloak_1 | clientscop0_.ID=?
keycloak_1 | 11:34:42,930 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (default task-22) KeycloakDS: getConnection(null, WrappedConnectionRequestInfo@4012a004[userName=keycloak]) [0/20]
keycloak_1 | 11:34:42,932 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (default task-22) Initiating JDBC connection release from afterStatement
keycloak_1 | 11:34:42,932 DEBUG [org.hibernate.loader.entity.plan.AbstractLoadPlanBasedEntityLoader] (default task-22) Done entity load : org.keycloak.models.jpa.entities.ClientScopeEntity#e770bbd8-54d9-4f5a-a008-07508a45f49f
keycloak_1 | 11:34:42,933 DEBUG [org.keycloak.saml.common] (default task-22) org.keycloak.saml.processing.core.saml.v2.util.XMLTimeUtil issueInstant: 2021-09-10T11:34:42.933Z
keycloak_1 | 11:34:42,933 DEBUG [org.keycloak.saml.common] (default task-22) org.keycloak.saml.processing.core.saml.v2.util.XMLTimeUtil issueInstant: 2021-09-10T11:34:42.933Z
keycloak_1 | 11:34:42,934 DEBUG [org.keycloak.saml.common] (default task-22) org.keycloak.saml.processing.core.saml.v2.util.XMLTimeUtil issueInstant: 2021-09-10T11:34:42.934Z
keycloak_1 | 11:34:42,934 DEBUG [org.keycloak.saml.common] (default task-22) org.keycloak.saml.processing.core.saml.v2.util.XMLTimeUtil issueInstant: 2021-09-10T11:34:42.934Z
keycloak_1 | 11:34:42,936 DEBUG [freemarker.cache] (default task-22) TemplateLoader.findTemplateSource("template_en_US.ftl"): Not found
keycloak_1 | 11:34:42,936 DEBUG [freemarker.cache] (default task-22) TemplateLoader.findTemplateSource("template_en.ftl"): Not found
keycloak_1 | 11:34:42,937 DEBUG [freemarker.cache] (default task-22) TemplateLoader.findTemplateSource("template.ftl"): Found
keycloak_1 | 11:34:42,937 DEBUG [freemarker.cache] (default task-22) "template.ftl"("en_US", UTF-8, parsed): using cached since file:/opt/jboss/keycloak/themes/base/login/template.ftl hasn't changed.
keycloak_1 | 11:34:42,938 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) MessageBodyWriter: org.jboss.resteasy.spi.ResteasyProviderFactory$SortedKey
keycloak_1 | 11:34:42,938 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) MessageBodyWriter: org.jboss.resteasy.plugins.providers.StringTextStar
keycloak_1 | 11:34:42,938 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) MessageBodyWriter: org.jboss.resteasy.plugins.providers.StringTextStar
keycloak_1 | 11:34:42,938 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) Interceptor Context: org.jboss.resteasy.core.interception.ServerWriterInterceptorContext, Method : proceed
keycloak_1 | 11:34:42,938 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) WriterInterceptor: org.jboss.resteasy.security.doseta.DigitalSigningInterceptor
keycloak_1 | 11:34:42,938 DEBUG [org.jboss.resteasy.security.doseta.i18n] (default task-22) Interceptor : org.jboss.resteasy.security.doseta.DigitalSigningInterceptor, Method : aroundWriteTo
keycloak_1 | 11:34:42,938 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) Interceptor Context: org.jboss.resteasy.core.interception.ServerWriterInterceptorContext, Method : proceed
keycloak_1 | 11:34:42,938 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) MessageBodyWriter: org.jboss.resteasy.spi.ResteasyProviderFactory$SortedKey
keycloak_1 | 11:34:42,938 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) MessageBodyWriter: org.jboss.resteasy.plugins.providers.StringTextStar
keycloak_1 | 11:34:42,939 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (default task-22) JtaTransactionWrapper commit
keycloak_1 | 11:34:42,939 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-22) Processing flush-time cascades
keycloak_1 | 11:34:42,939 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-22) Dirty checking collections
keycloak_1 | 11:34:42,939 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-22) Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
keycloak_1 | 11:34:42,939 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-22) Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
keycloak_1 | 11:34:42,939 DEBUG [org.hibernate.internal.util.EntityPrinter] (default task-22) Listing entities:
keycloak_1 | 11:34:42,939 DEBUG [org.hibernate.internal.util.EntityPrinter] (default task-22) org.keycloak.events.jpa.EventEntity{clientId=SamlTest01, realmId=master, ipAddress=46.44.215.210, id=9556f19b-7824-425a-bcce-b7a04215b6fe, sessionId=e628f22a-abd5-4d18-87eb-faffa4d5dc51, time=1631273682928, error=null, type=LOGIN, userId=6ba03c79-2dc7-487f-9364-ed61e14ab676, detailsJson={"auth_method":"saml","consent":"no_consent_required","code_id":"e628f22a-abd5-4d18-87eb-faffa4d5dc51","username":"test1"}}
keycloak_1 | 11:34:42,939 DEBUG [org.hibernate.SQL] (default task-22)
keycloak_1 | insert
keycloak_1 | into
keycloak_1 | EVENT_ENTITY
keycloak_1 | (CLIENT_ID, DETAILS_JSON, ERROR, IP_ADDRESS, REALM_ID, SESSION_ID, EVENT_TIME, TYPE, USER_ID, ID)
keycloak_1 | values
keycloak_1 | (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
keycloak_1 | 11:34:42,940 DEBUG [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (default task-22) Skipping aggressive release due to manual disabling
keycloak_1 | 11:34:42,941 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (default task-22) Initiating JDBC connection release from afterStatement
keycloak_1 | 11:34:42,941 DEBUG [org.hibernate.engine.transaction.internal.TransactionImpl] (default task-22) On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
keycloak_1 | 11:34:42,946 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (default task-22) KeycloakDS: returnConnection(2582e92c, false) [0/20]
keycloak_1 | 11:34:42,946 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (default task-22) Initiating JDBC connection release from afterTransaction
keycloak_1 | 11:34:42,946 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (default task-22) JtaTransactionWrapper end
keycloak_1 | 11:34:42,946 DEBUG [org.keycloak.events] (default task-22) type=LOGIN, realmId=master, clientId=SamlTest01, userId=6ba03c79-2dc7-487f-9364-ed61e14ab676, ipAddress=46.44.215.210, auth_method=saml, consent=no_consent_required, code_id=e628f22a-abd5-4d18-87eb-faffa4d5dc51, username=test1, authSessionParentId=e628f22a-abd5-4d18-87eb-faffa4d5dc51, authSessionTabId=rVV5HB4YJss
keycloak_1 | 11:34:43,141 DEBUG [io.undertow.request] (default I/O-7) Matched prefix path /auth for path /auth/realms/master/login-actions/authenticate
keycloak_1 | 11:34:43,141 DEBUG [io.undertow.request.security] (default task-22) Attempting to authenticate /auth/realms/master/login-actions/authenticate, authentication required: false
keycloak_1 | 11:34:43,141 DEBUG [io.undertow.request.security] (default task-22) Authentication outcome was NOT_ATTEMPTED with method io.undertow.security.impl.CachedAuthenticatedSessionMechanism@2862f3b6 for /auth/realms/master/login-actions/authenticate
keycloak_1 | 11:34:43,141 DEBUG [io.undertow.request.security] (default task-22) Authentication result was ATTEMPTED for /auth/realms/master/login-actions/authenticate
keycloak_1 | 11:34:43,141 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (default task-22) new JtaTransactionWrapper
keycloak_1 | 11:34:43,141 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (default task-22) was existing? false
keycloak_1 | 11:34:43,142 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) RESTEASY002315: PathInfo: /realms/master/login-actions/authenticate
keycloak_1 | 11:34:43,142 DEBUG [org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl] (default task-22) Hibernate RegisteredSynchronization successfully registered with JTA platform
keycloak_1 | 11:34:43,142 DEBUG [org.keycloak.services.resources.SessionCodeChecks] (default task-22) Will use client 'SamlTest01' in back-to-application link
keycloak_1 | 11:34:43,143 DEBUG [org.keycloak.services.util.CookieHelper] (default task-22) AUTH_SESSION_ID cookie found in the request header
keycloak_1 | 11:34:43,143 DEBUG [org.keycloak.services.util.CookieHelper] (default task-22) AUTH_SESSION_ID cookie found in the cookie field
keycloak_1 | 11:34:43,143 DEBUG [org.keycloak.services.managers.AuthenticationSessionManager] (default task-22) Found AUTH_SESSION_ID cookie with value e628f22a-abd5-4d18-87eb-faffa4d5dc51.4cabab710c64
keycloak_1 | 11:34:43,143 DEBUG [org.keycloak.services.util.CookieHelper] (default task-22) AUTH_SESSION_ID cookie found in the request header
keycloak_1 | 11:34:43,143 DEBUG [org.keycloak.services.util.CookieHelper] (default task-22) AUTH_SESSION_ID cookie found in the cookie field
keycloak_1 | 11:34:43,143 DEBUG [org.keycloak.services.managers.AuthenticationSessionManager] (default task-22) Found AUTH_SESSION_ID cookie with value e628f22a-abd5-4d18-87eb-faffa4d5dc51.4cabab710c64
keycloak_1 | 11:34:43,144 DEBUG [freemarker.cache] (default task-22) TemplateLoader.findTemplateSource("template_en_US.ftl"): Not found
keycloak_1 | 11:34:43,144 DEBUG [freemarker.cache] (default task-22) TemplateLoader.findTemplateSource("template_en.ftl"): Not found
keycloak_1 | 11:34:43,144 DEBUG [freemarker.cache] (default task-22) TemplateLoader.findTemplateSource("template.ftl"): Found
keycloak_1 | 11:34:43,144 DEBUG [freemarker.cache] (default task-22) "template.ftl"("en_US", UTF-8, parsed): using cached since file:/opt/jboss/keycloak/themes/base/login/template.ftl hasn't changed.
keycloak_1 | 11:34:43,145 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) MessageBodyWriter: org.jboss.resteasy.spi.ResteasyProviderFactory$SortedKey
keycloak_1 | 11:34:43,145 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) MessageBodyWriter: org.jboss.resteasy.plugins.providers.StringTextStar
keycloak_1 | 11:34:43,145 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) MessageBodyWriter: org.jboss.resteasy.plugins.providers.StringTextStar
keycloak_1 | 11:34:43,145 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) Interceptor Context: org.jboss.resteasy.core.interception.ServerWriterInterceptorContext, Method : proceed
keycloak_1 | 11:34:43,145 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) WriterInterceptor: org.jboss.resteasy.security.doseta.DigitalSigningInterceptor
keycloak_1 | 11:34:43,145 DEBUG [org.jboss.resteasy.security.doseta.i18n] (default task-22) Interceptor : org.jboss.resteasy.security.doseta.DigitalSigningInterceptor, Method : aroundWriteTo
keycloak_1 | 11:34:43,145 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) Interceptor Context: org.jboss.resteasy.core.interception.ServerWriterInterceptorContext, Method : proceed
keycloak_1 | 11:34:43,145 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) MessageBodyWriter: org.jboss.resteasy.spi.ResteasyProviderFactory$SortedKey
keycloak_1 | 11:34:43,145 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-22) MessageBodyWriter: org.jboss.resteasy.plugins.providers.StringTextStar
keycloak_1 | 11:34:43,146 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (default task-22) JtaTransactionWrapper commit
keycloak_1 | 11:34:43,146 DEBUG [org.hibernate.engine.transaction.internal.TransactionImpl] (default task-22) On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
keycloak_1 | 11:34:43,146 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (default task-22) Initiating JDBC connection release from afterTransaction
keycloak_1 | 11:34:43,146 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (default task-22) JtaTransactionWrapper end
keycloak_1 | 11:34:47,399 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) new JtaTransactionWrapper
keycloak_1 | 11:34:47,399 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) was existing? false
keycloak_1 | 11:34:47,399 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) JtaTransactionWrapper commit
keycloak_1 | 11:34:47,400 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) JtaTransactionWrapper end