[keycloak-user] Issue with SAML AuthnRequest
Luis Rodríguez Fernández
uo67113 at gmail.com
Wed Feb 6 08:13:46 EST 2019
Hello Max,
May I ask you what is the client implementation? For my dev environment,
using the tomcat saml adapter in the SP side and Keycloak
4.8.2.Final-SNAPSHOT in the IdP one is working:
- SP:
- jdk1.8.0_191
- Apache Tomcat 8.0.14
- keycloak tomcat saml adapter 4.8.2.Final-SNAPSHOT
- <SingleSignOnService signRequest="true"
validateResponseSignature="true"
requestBinding="POST"
bindingUrl="
http://localhost:8081/auth/realms/demo/protocol/saml"/>
- IdP:
- jdk1.8.0_191
- keycloak 4.8.2.Final-SNAPSHOT (from
org.keycloak:keycloak-testsuite-utils)
If your client uses keycloak, at least in the java adapter you can define
the signatureCanonicalizationMethod, but usually the default one (
http://www.w3.org/2001/10/xml-exc-c14n#) is OK. Check in your client if you
can customize this.
Hope it helps,
Luis
El mar., 5 feb. 2019 a las 11:11, <max at mascanc.net> escribió:
> Hi All,
>
> I'm using KeyCloack keycloak-4.8.3.Final with Java build
> 1.8.0_151-b12 as SAML Identity provider. My client sends signed SAML
> AuthnRequests using the HTTP POST Web Browser SSO profile, and keycloack
> fails verifying
> the siganture (different digests).
>
> By dumping the SAMLRequest message with wireshark in the keycloack
> machine and validating its signature with Oxygen 12, the signature is
> fine. However keycloack has an issue verifying it, with the attached log.
>
> This is usually a canonicalization problem. I could provide the TCPDumps
> to reproduce the error.
>
> Any idea?
>
> Thanks a lot!
>
>
>
>
> 2019-02-04 17:10:38,458 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) new
> JtaTransactionWrapper
> 2019-02-04 17:10:38,459 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) was existing?
> false
> 2019-02-04 17:10:38,459 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2)
> JtaTransactionWrapper commit
> 2019-02-04 17:10:38,459 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2)
> JtaTransactionWrapper end
> 2019-02-04 17:10:38,459 DEBUG
> [org.keycloak.services.scheduled.ScheduledTaskRunner] (Timer-2) Executed
> scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$783/1903918206
> 2019-02-04 17:10:43,458 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) new
> JtaTransactionWrapper
> 2019-02-04 17:10:43,458 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) was existing?
> false
> 2019-02-04 17:10:43,458 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2)
> JtaTransactionWrapper commit
> 2019-02-04 17:10:43,458 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2)
> JtaTransactionWrapper end
> 2019-02-04 17:10:43,458 DEBUG
> [org.keycloak.services.scheduled.ScheduledTaskRunner] (Timer-2) Executed
> scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$783/1903918206
> 2019-02-04 17:10:48,459 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) new
> JtaTransactionWrapper
> 2019-02-04 17:10:48,459 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) was existing?
> false
> 2019-02-04 17:10:48,459 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2)
> JtaTransactionWrapper commit
> 2019-02-04 17:10:48,459 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2)
> JtaTransactionWrapper end
> 2019-02-04 17:10:48,459 DEBUG
> [org.keycloak.services.scheduled.ScheduledTaskRunner] (Timer-2) Executed
> scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$783/1903918206
> 2019-02-04 17:10:53,459 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) new
> JtaTransactionWrapper
> 2019-02-04 17:10:53,460 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) was existing?
> false
> 2019-02-04 17:10:53,460 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2)
> JtaTransactionWrapper commit
> 2019-02-04 17:10:53,460 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2)
> JtaTransactionWrapper end
> 2019-02-04 17:10:53,460 DEBUG
> [org.keycloak.services.scheduled.ScheduledTaskRunner] (Timer-2) Executed
> scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$783/1903918206
> 2019-02-04 17:10:58,459 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) new
> JtaTransactionWrapper
> 2019-02-04 17:10:58,459 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) was existing?
> false
> 2019-02-04 17:10:58,460 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2)
> JtaTransactionWrapper commit
> 2019-02-04 17:10:58,460 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2)
> JtaTransactionWrapper end
> 2019-02-04 17:10:58,460 DEBUG
> [org.keycloak.services.scheduled.ScheduledTaskRunner] (Timer-2) Executed
> scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$783/1903918206
> 2019-02-04 17:10:59,520 DEBUG [io.undertow.request] (default I/O-3)
> Matched prefix path /auth for path /auth/realms/master/protocol/saml
> 2019-02-04 17:10:59,521 DEBUG [io.undertow.request.security] (default
> task-97) Attempting to authenticate /auth/realms/master/protocol/saml,
> authentication required: false
> 2019-02-04 17:10:59,521 DEBUG [io.undertow.request.security] (default
> task-97) Authentication outcome was NOT_ATTEMPTED with method
> io.undertow.security.impl.CachedAuthenticatedSessionMechanism at 7238f9bf
> for /auth/realms/master/protocol/saml
> 2019-02-04 17:10:59,521 DEBUG [io.undertow.request.security] (default
> task-97) Authentication result was ATTEMPTED for
> /auth/realms/master/protocol/saml
> 2019-02-04 17:10:59,521 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (default task-97) new
> JtaTransactionWrapper
> 2019-02-04 17:10:59,521 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (default task-97) was
> existing? false
> 2019-02-04 17:10:59,522 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
> (default task-97) RESTEASY002315: PathInfo: /realms/master/protocol/saml
> 2019-02-04 17:10:59,522 DEBUG
> [org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl]
> (default task-97) Hibernate RegisteredSynchronization successfully
> registered with JTA platform
> 2019-02-04 17:10:59,523 DEBUG [org.keycloak.protocol.saml.SamlService]
> (default task-97) SAML POST
> 2019-02-04 17:10:59,524 DEBUG [org.keycloak.saml.SAMLRequestParser]
> (default task-97) SAML POST Binding
> 2019-02-04 17:10:59,524 DEBUG [org.keycloak.saml.SAMLRequestParser]
> (default task-97) <?xml version="1.0"
> encoding="UTF-8"?><saml2p:AuthnRequest
> xmlns:saml2p="urn:oasis:names:tc:SAML:2.0:protocol"
> AssertionConsumerServiceURL="
> https://kv-pfg:8543/SpiritHealthPortal/SamlReceiver" Destination="
> http://kv-sws:8080/auth/realms/master/protocol/saml" ForceAuthn="true"
> ID="46faa8d7-fd71-4c00-8badask-97) setElement(ds:CanonicalizationMethod,
> "null")
> 2019-02-04 17:10:59,529 DEBUG
> [org.apache.jcp.xml.dsig.internal.dom.ApacheCanonicalizer] (default
> task-97) Created transform for algorithm:
> http://www.w3.org/2001/10/xml-exc-c14n#
> 2019-02-04 <http://www.w3.org/2001/10/xml-exc-c14n#2019-02-04>
> 17:10:59,529 DEBUG
> [org.apache.jcp.xml.dsig.internal.dom.ApacheCanonicalizer] (default
> task-97) isNodeSet() = true
> 2019-02-04 17:10:59,529 DEBUG
> [org.apache.jcp.xml.dsig.internal.dom.DOMSignedInfo] (default task-97)
> Canonicalized SignedInfo:
> 2019-02-04 17:10:59,529 DEBUG
> [org.apache.jcp.xml.dsig.internal.dom.DOMSignedInfo] (default task-97)
> <ds:SignedInfo xmlns:ds="http://www.w3.org/2000/09/xmldsig#"><ds:CanonicalizationMethod
> Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></ds:CanonicalizationMethod><ds:SignatureMethod
> Algorithm="http://www.w3.org/2000/09/xmldsig#rsa-sha1"></ds:SignatureMethod><ds:Reference
> URI="#46faa8d7-fd71-4c00-8bad-921a5bd9e5c8"><ds:Transforms><ds:Transform
> Algorithm="http://www.w3.org/2000/09/xmldsig#enveloped-signature"></ds:Transform><ds:Transform
> Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></ds:Transform></ds:Transforms><ds:DigestMethod
> Algorithm="http://www.w3.org/2001/04/xmlenc#sha256
> "></ds:DigestMethod><ds:DigestValue>bcAIFrQ6IYwak1tF9MQgcoxBFm5pWy+0xJxlt0C8mzU=</ds:DigestValue></ds:Reference></ds:SignedInfo>
> 2019-02-04 17:10:59,529 DEBUG
> [org.apache.jcp.xml.dsig.internal.dom.DOMSignedInfo] (default task-97) Data
> to be
> signed/verified:PGRzOlNpZ25lZEluZm8geG1sbnM6ZHM9Imh0dHA6Ly93d3cudzMub3JnLzIwMDAvMDkveG1sZHNpZyMiPjxkczpDYW5vbmljYWxpemF0aW9uTWV0aG9kIEFsZ29yaXRobT0iaHR0cDovL3d3dy53My5vcmcvMjAwMS8xMC94bWwtZXhjLWMxNG4jIj48L2RzOkNhbm9uaWNhbGl6YXRpb25NZXRob2Q+PGRzOlNpZ25hdHVyZU1ldGhvZCBBbGdvcml0aG09Imh0dHA6Ly93d3cudzMub3JnLzIwMDAvMDkveG1sZHNpZyNyc2Etc2hhMSI+PC9kczpTaWduYXR1cmVNZXRob2Q+PGRzOlJlZmVyZW5jZSBVUkk9IiM0NmZhYThkNy1mZDcxLTRjMDAtOGJhZC05MjFhNWJkOWU1YzgiPjxkczpUcmFuc2Zvcm1zPjxkczpUcmFuc2Zvcm0gQWxnb3JpdGhtPSJodHRwOi8vd3d3LnczLm9yZy8yMDAwLzA5L3htbGRzaWcjZW52ZWxvcGVkLXNpZ25hdHVyZSI+PC9kczpUcmFuc2Zvcm0+PGRzOlRyYW5zZm9ybSBBbGdvcml0aG09Imh0dHA6Ly93d3cudzMub3JnLzIwMDEvMTAveG1sLWV4Yy1jMTRuIyI+PC9kczpUcmFuc2Zvcm0+PC9kczpUcmFuc2Zvcm1zPjxkczpEaWdlc3RNZXRob2QgQWxnb3JpdGhtPSJodHRwOi8vd3d3LnczLm9yZy8yMDAxLzA0L3htbGVuYyNzaGEyNTYiPjwvZHM6RGlnZXN0TWV0aG9kPjxkczpEaWdlc3RWYWx1ZT5iY0FJRnJRNklZd2FrM!
>
> XRGOU1RZ2NveEJGbTVwV3krMHhKeGx0MEM4bXpVPTwvZHM6RGlnZXN0VmFsdWU+PC9kczpSZWZlcmVuY2U+PC9kczpTaWduZWRJbmZvPg==
> 2019-02-04 17:10:59,530 ERROR [org.keycloak.protocol.saml.SamlService]
> (default task-97) request validation failed:
> org.keycloak.common.VerificationException: Invalid signature on document
> at
> org.keycloak.protocol.saml.SamlProtocolUtils.verifyDocumentSignature(SamlProtocolUtils.java:83)
> at
> org.keycloak.protocol.saml.SamlProtocolUtils.verifyDocumentSignature(SamlProtocolUtils.java:68)
> at
> org.keycloak.protocol.saml.SamlService$PostBindingProtocol.verifySignature(SamlService.java:501)
> at
> org.keycloak.protocol.saml.SamlService$BindingProtocol.handleSamlRequest(SamlService.java:244)
> at
> org.keycloak.protocol.saml.SamlService$BindingProtocol.execute(SamlService.java:491)
> at
> org.keycloak.protocol.saml.SamlService.postBinding(SamlService.java:581)
> at sun.reflect.GeneratedMethodAccessor871.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:140)
> at
> org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:509)
> at
> org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:399)
> at
> org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$0(ResourceMethodInvoker.java:363)
> at
> org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:358)
> at
> org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:365)
> at
> org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:337)
> at
> org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:137)
> at
> org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:100)
> at
> org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:443)
> at
> org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:233)
> at
> org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:139)
> at
> org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:358)
> at
> org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:142)
> at
> org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:219)
> at
> org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:227)
> at
> org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
> at
> org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:791)
> at
> io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
> at
> io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
> at
> org.keycloak.services.filters.KeycloakSessionServletFilter.doFilter(KeycloakSessionServletFilter.java:90)
> at
> io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
> at
> io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
> at
> io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
> at
> io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
> at
> io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
> at
> io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
> at
> org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
> at
> io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
> at
> io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:132)
> at
> io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
> at
> io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
> at
> io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
> at
> io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
> at
> io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
> at
> io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
> at
> io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
> at
> io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
> at
> io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
> at
> org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
> at
> io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
> at
> org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
> at
> io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
> at
> io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292)
> at
> io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
> at
> io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
> at
> io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
> at
> io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
> at
> io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
> at
> org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
> at
> org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
> at
> org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
> at
> org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
> at
> org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
> at
> io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
> at
> io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
> at
> io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
> at
> io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
> at
> io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
> at
> org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
> at
> org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
> at
> org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
> at
> org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
> at java.lang.Thread.run(Thread.java:748)
>
> 2019-02-04 17:10:59,531 DEBUG
> [org.hibernate.event.internal.AbstractSaveEventListener] (default task-97)
> Generated identifier: d4e07837-2fa9-4a74-9971-5847bbe24e88, using strategy:
> org.hibernate.id.Assigned
> 2019-02-04 17:10:59,532 WARN [org.keycloak.events] (default task-97)
> type=LOGIN_ERROR, realmId=master, clientId=null, userId=null,
> ipAddress=10.10.10.54, error=invalid_signature
> 2019-02-04 17:10:59,532 DEBUG [freemarker.cache] (default task-97)
> Couldn't find template in cache for "error.ftl"("en_US", UTF-8, parsed);
> will try to load it.
> 2019-02-04 17:10:59,532 DEBUG [freemarker.cache] (default task-97)
> TemplateLoader.findTemplateSource("error_en_US.ftl"): Not found
> 2019-02-04 17:10:59,532 DEBUG [freemarker.cache] (default task-97)
> TemplateLoader.findTemplateSource("error_en.ftl"): Not found
> 2019-02-04 17:10:59,532 DEBUG [freemarker.cache] (default task-97)
> TemplateLoader.findTemplateSource("error.ftl"): Found
> 2019-02-04 17:10:59,532 DEBUG [freemarker.cache] (default task-97) Loading
> template for "error.ftl"("en_US", UTF-8, parsed) from
> "file:/opt/keycloak/themes/base/login/error.ftl"
> 2019-02-04 17:10:59,533 DEBUG [freemarker.cache] (default task-97)
> Couldn't find template in cache for "template.ftl"("en_US", UTF-8, parsed);
> will try to load it.
> 2019-02-04 17:10:59,534 DEBUG [freemarker.cache] (default task-97)
> TemplateLoader.findTemplateSource("template_en_US.ftl"): Not found
> 2019-02-04 17:10:59,534 DEBUG [freemarker.cache] (default task-97)
> TemplateLoader.findTemplateSource("template_en.ftl"): Not found
> 2019-02-04 17:10:59,534 DEBUG [freemarker.cache] (default task-97)
> TemplateLoader.findTemplateSource("template.ftl"): Found
> 2019-02-04 17:10:59,534 DEBUG [freemarker.cache] (default task-97) Loading
> template for "template.ftl"("en_US", UTF-8, parsed) from
> "file:/opt/keycloak/themes/base/login/template.ftl"
> 2019-02-04 17:10:59,538 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (default task-97)
> JtaTransactionWrapper commit
> 2019-02-04 17:10:59,538 DEBUG
> [org.hibernate.event.internal.AbstractFlushingEventListener] (default
> task-97) Processing flush-time cascades
> 2019-02-04 17:10:59,538 DEBUG
> [org.hibernate.event.internal.AbstractFlushingEventListener] (default
> task-97) Dirty checking collections
> 2019-02-04 17:10:59,538 DEBUG
> [org.hibernate.event.internal.AbstractFlushingEventListener] (default
> task-97) Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
> 2019-02-04 17:10:59,538 DEBUG
> [org.hibernate.event.internal.AbstractFlushingEventListener] (default
> task-97) Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
> 2019-02-04 17:10:59,538 DEBUG [org.hibernate.internal.util.EntityPrinter]
> (default task-97) Listing entities:
> 2019-02-04 17:10:59,538 DEBUG [org.hibernate.internal.util.EntityPrinter]
> (default task-97) org.keycloak.events.jpa.EventEntity{clientId=null,
> realmId=master, ipAddress=10.10.10.54,
> id=d4e07837-2fa9-4a74-9971-5847bbe24e88, sessionId=null,
> time=1549296659531, error=invalid_signature, type=LOGIN_ERROR, userId=null,
> detailsJson=null}
> 2019-02-04 17:10:59,539 DEBUG [org.hibernate.SQL] (default task-97)
> insert
> into
> EVENT_ENTITY
> (CLIENT_ID, DETAILS_JSON, ERROR, IP_ADDRESS, REALM_ID, SESSION_ID,
> EVENT_TIME, TYPE, USER_ID, ID)
> values
> (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
> 2019-02-04 17:10:59,539 DEBUG
> [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (default
> task-97) KeycloakDS: getConnection(null,
> WrappedConnectionRequestInfo at 2116b544[userName=keycloak]) [0/15]
> 2019-02-04 17:10:59,544 DEBUG
> [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (default task-97)
> Skipping aggressive release due to manual disabling
> 2019-02-04 17:10:59,544 DEBUG
> [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl]
> (default task-97) Initiating JDBC connection release from afterStatement
> 2019-02-04 17:10:59,546 DEBUG
> [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl]
> (default task-97) Initiating JDBC connection release from afterTransaction
> 2019-02-04 17:10:59,546 DEBUG
> [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (default
> task-97) KeycloakDS: returnConnection(27223045, false) [0/15]
> 2019-02-04 17:10:59,547 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (default task-97)
> JtaTransactionWrapper end
> 2019-02-04 17:10:59,547 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
> (default task-97) MessageBodyWriter:
> org.jboss.resteasy.spi.ResteasyProviderFactory$SortedKey
> 2019-02-04 17:10:59,547 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
> (default task-97) MessageBodyWriter:
> org.jboss.resteasy.plugins.providers.ByteArrayProvider
> 2019-02-04 17:10:59,547 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
> (default task-97) MessageBodyWriter:
> org.jboss.resteasy.plugins.providers.ByteArrayProvider
> 2019-02-04 17:10:59,547 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
> (default task-97) Interceptor Context:
> org.jboss.resteasy.core.interception.ServerWriterInterceptorContext,
> Method : proceed
> 2019-02-04 17:10:59,547 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
> (default task-97) WriterInterceptor:
> org.jboss.resteasy.security.doseta.DigitalSigningInterceptor
> 2019-02-04 17:10:59,547 DEBUG [org.jboss.resteasy.security.doseta.i18n]
> (default task-97) Interceptor :
> org.jboss.resteasy.security.doseta.DigitalSigningInterceptor, Method :
> aroundWriteTo
> 2019-02-04 17:10:59,547 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
> (default task-97) Interceptor Context:
> org.jboss.resteasy.core.interception.ServerWriterInterceptorContext,
> Method : proceed
> 2019-02-04 17:10:59,547 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
> (default task-97) MessageBodyWriter:
> org.jboss.resteasy.spi.ResteasyProviderFactory$SortedKey
> 2019-02-04 17:10:59,547 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
> (default task-97) MessageBodyWriter:
> org.jboss.resteasy.plugins.providers.ByteArrayProvider
> 2019-02-04 17:10:59,547 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
> (default task-97) Provider :
> org.jboss.resteasy.plugins.providers.ByteArrayProvider, Method : writeTo
> 2019-02-04 17:11:03,459 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) new
> JtaTransactionWrapper
> 2019-02-04 17:11:03,459 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) was existing?
> false
> 2019-02-04 17:11:03,459 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2)
> JtaTransactionWrapper commit
> 2019-02-04 17:11:03,459 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2)
> JtaTransactionWrapper end
> 2019-02-04 17:11:03,459 DEBUG
> [org.keycloak.services.scheduled.ScheduledTaskRunner] (Timer-2) Executed
> scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$783/1903918206
> 2019-02-04 17:11:08,459 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) new
> JtaTransactionWrapper
> 2019-02-04 17:11:08,460 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) was existing?
> false
> 2019-02-04 17:11:08,460 DEBUG
> [org.keycloak.models.sessions.infinispan.changes.sessions.PersisterLastSessionRefreshStore]
> (Timer-2) Updating 0 userSessions with lastSessionRefresh: 1549296608
> 2019-02-04 17:11:08,460 DEBUG
> [org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl]
> (Timer-2) Hibernate RegisteredSynchronization successfully registered with
> JTA platform
> 2019-02-04 17:11:08,460 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2)
> JtaTransactionWrapper commit
> 2019-02-04 17:11:08,460 DEBUG
> [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl]
> (Timer-2) Initiating JDBC connection release from afterTransaction
> 2019-02-04 17:11:08,460 DEBUG
> [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2)
> JtaTransactionWrapper end
> 2019-02-04 17:11:08,460 DEBUG
> [org.keycloak.services.scheduled.ScheduledTaskRunner] (Timer-2) Executed
> scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$783/1903918206
>
> _______________________________________________
> keycloak-user mailing list
> keycloak-user at lists.jboss.org
> https://lists.jboss.org/mailman/listinfo/keycloak-user
>
--
"Ever tried. Ever failed. No matter. Try Again. Fail again. Fail better."
- Samuel Beckett
More information about the keycloak-user
mailing list