[keycloak-user] Issue with SAML AuthnRequest
max at mascanc.net
max at mascanc.net
Tue Feb 5 05:09:34 EST 2019
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 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+PC9kczpUcmFuc2Zvcm1zPjxkczpEaWdlc3RNZXRob2QgQWxnb3JpdGhtPSJodHRwOi8vd3d3LnczLm9yZy8yMDAxLzA0L3htbGVuYyNzaGEyNTYiPjwvZHM6RGlnZXN0TWV0aG9kPjxkczpEaWdlc3RWYWx1ZT5iY0FJRnJRNklZd2FrMXRGOU1RZ2NveEJGbTVwV3krMHhKeGx0MEM4bXpVPTwvZHM6RGlnZXN0VmFsdWU+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
More information about the keycloak-user
mailing list