Re: [keycloak-user] Issue with SAML AuthnRequest

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@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:Canonic... Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></ds:... Algorithm="http://www.w3.org/2000/09/xmldsig#rsa-sha1"></... URI="#46faa8d7-fd71-4c00-8bad-921a5bd9e5c8"><ds:Transforms><ds:Transform Algorithm="http://www.w3.org/2000/09/xmldsig#enveloped-signature&quo... Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></ds:... 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@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(a)lists.jboss.org https://lists.jboss.org/mailman/listinfo/keycloak-user