Issue with SAML AuthnRequest
by max@mascanc.net
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 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@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
5 years, 2 months
Http CIP and Client's Access Token
by Alexey Titorenko
Hello guys!
Could someone please help me with my investigation of PolicyEnforcer?
I’m currently checking how ‘http’ claim information point is working.
Let’s imagine typical situation when some client calls service, which, it turn, uses ‘http’ CIP. That is, we have following scheme: CLIENT -> Service -> ClaimSerivce
The question is about the token, which is used to call ClaimService. I would expect, that Service should get its own token which provides access to ClaimService. But I see, that it uses CLIENT’s token. Which imho means, that:
Client knows from his token about this ClaimService although he shouldn’t from the security point of view. Although, it some schemes it may be required, I agree. But not always.
Service calls ClaimService using not his own rights, but client’s rights, which makes it more difficult to control and audit access.
Usage of ClaimService is an internal detail of the Service and may change at any time. In this case we need to reconfigure tokens for all clients calling Service, which is, again, not good.
What do you think about this? Am I right or wrong? Or should we consider OOTB 'http' CIP as a reference only?
Also, http CIP does not support path parameters, which is typical situation for REST. Only query parameters.
Alexey
5 years, 2 months
Policy Evaluation Rules
by Alexey Titorenko
Hello guys!
Could you please help me with understanding how policies are evaluated?
I have REST service with several operations. Each of them is protected by corresponding scope (create, view, update, delete, list). For each of these scopes I defined scope based permission which controls access to its scope.
All of the permissions have just one ‘Default’ policy, which grants access to any user. An ‘delete’ permissions in addition has JavaScript-based policy which checks if caller is author of the document. So, only one permission is configured to evaluate ‘Author’ policy.
I expect, that ‘Author’ policy will only be evaluated, when ‘delete’ operation on service is called. But I see, that it is evaluated each time ANY operation is called.
So, if all policies are evaluated for each call, then what is a purpose of specifying policies in permissions? What is a right way to use policies then?
Thank you,
Alexey.
5 years, 2 months
UserAttributeMapper with an Identity Provider : not working on first connection (importNewUser), working on next connections (updateBrokeredUser)
by Jean-François HEROUARD
Hi,
I find a strange behaviour when using mappers with an identity providers
(tested on old KC 3.4 but also on KC 4.8.3).
Here is my case:
I configured an OIDC identity provider with the following mappers :
- Claim to role: if token has claim "LICORNCLAIM" with value "true" then
user has role "WONDERFULROLE"
- Attribute importer: import token claim "LICORNCLAIM" as user attribute
On first connection (external to internal token exchange), user is created
and has only the role, not the attribute. On next token exchange, user has
the attribute and the role.
After some debug I found that TokenEndpoint.importUserFromExternalIdentity
behaves differently if user already exists or not (import new user or
update it). UserAttributeMapper is implementing "updateBrokeredUser" but
not "importNewUser" (abstract method does nothing). AttributeToRoleMapper
class overrides both methods and works well. Most
AbstractIdentityProviderMapper implementations also overrides both.
Should I open a JIRA for this ?
Thanks.
5 years, 2 months
Restrict access to admin console by checking if header exists
by Mark de Jng
Hi,
I want to restrict the access to admin console by checking if the `CF-Connecting-IP` does not exist for a specific path.
I’ve checked this documentation: http://undertow.io/undertow-docs/undertow-docs-2.0.0/#predicates-attributes-and-handlers
And I’ve come this far, but undertow complains that my expression is not valid:
<expression-filtermodule="io.undertow.core" name="restrict-admin-console-access" expression="path-prefix(/auth/admin/console) and not exists(%{i, CF-Connecting-IP})" />
Any clue?
Thanks
Mark
5 years, 2 months
Remove realm in HA environment throw org.keycloak.models.ModelException: javax.persistence.OptimisticLockException
by madhura nishshanka
Hi All,
I am getting "org.keycloak.models.ModelException:
javax.persistence.OptimisticLockException: Batch update returned unexpected
row count from update [0]; actual row count: 0; expected: 1" When a realm
is delte from keycloak java admin client. This occurs in a HA environment
when we do a performance test. Can someone please help me on this?
I am using keycloak 4.8.1 final.
Full exception
11:56:25,452 ERROR [org.keycloak.services.error.KeycloakErrorHandler]
(default task-2) Uncaught server error: org.keycloak.models.ModelException:
javax.persistence.OptimisticLockException: Batch update returned unexpected
row count from update [0]; actual row count: 0; expected: 1
at
org.keycloak.connections.jpa.PersistenceExceptionConverter.convert(PersistenceExceptionConverter.java:61)
at
org.keycloak.connections.jpa.PersistenceExceptionConverter.invoke(PersistenceExceptionConverter.java:51)
at com.sun.proxy.$Proxy99.flush(Unknown Source)
at
org.keycloak.models.jpa.JpaRealmProvider.removeRole(JpaRealmProvider.java:320)
at
org.keycloak.models.jpa.JpaRealmProvider.removeClient(JpaRealmProvider.java:567)
at
*org.keycloak.models.jpa.JpaRealmProvider.removeRealm(JpaRealmProvider.java:153)*
at
org.keycloak.models.cache.infinispan.RealmCacheSession.removeRealm(RealmCacheSession.java:486)
at
org.keycloak.services.managers.RealmManager.removeRealm(RealmManager.java:248)
at
org.keycloak.services.resources.admin.RealmAdminResource.deleteRealm(RealmAdminResource.java:453)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
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:106)
at
org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:132)
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)
Caused by: javax.persistence.OptimisticLockException: Batch update returned
unexpected row count from update [0]; actual row count: 0; expected: 1
at
org.hibernate.internal.ExceptionConverterImpl.wrapStaleStateException(ExceptionConverterImpl.java:238)
at
org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:93)
at
org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:181)
at
org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:188)
at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1460)
at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1440)
at sun.reflect.GeneratedMethodAccessor483.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.keycloak.connections.jpa.PersistenceExceptionConverter.invoke(PersistenceExceptionConverter.java:49)
... 78 more
Caused by: org.hibernate.StaleStateException: Batch update returned
unexpected row count from update [0]; actual row count: 0; expected: 1
at
org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:67)
at
org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:54)
at
org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:46)
at
org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3478)
at
org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3735)
at
org.hibernate.action.internal.EntityDeleteAction.execute(EntityDeleteAction.java:99)
at
org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
at
org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:478)
at
org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:356)
at
org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1454)
... 83 more
Thanks
Madhura
5 years, 2 months
assign client roles to a user using keycloak rest API
by Dimitris Charlaftis
Hello,
I want to assign a client role to a specfic user using keycloak rest API.
From the documentaion, i tried this:
I have a realm called internal_applications and a client under this
realm called test_app. In this client (test_app), I have manually
created some client roles, i.e. administrator.
Then, I hit the server with postman
HTTP POST http://<keycloak-server-url>/auth/admin/realms/<realm-name>/users
BODY:
{
"username": "jim(a)ka.gr <http://ka.gr/>",
"firstName": "Jim",
"lastName": "Sanders",
"email": "jim(a)ka.gr <http://ka.gr/>",
"clientRoles": {
"test_app": ["administrator"]
}
}
This http call adds the user jim(a)ka.gr to keycloak, but DOES NOT ASSIGN
the already existing client role administrator to him.
How can I do this?
Please, help...
Dimitris
--
_____________________________
Dimitris Charlaftis
Software Engineer
National Documentation Center
email: dharlaftis(a)ekt.gr
_____________________________
---
This email has been checked for viruses by AVG.
https://www.avg.com
5 years, 2 months
Get the realms through the Client Admin Api
by Felix Knecht
Ciao Luca
In my case it turned out, that the TestEasy client used the wrong annotations provider. So the @JsonProperty <access_token> was not recognized and was null therefore.
What helped in my case was to set the annotation provider explicitely:
ResteasyClientBuilder clientBuilder = new ResteasyClientBuilder()
.connectionPoolSize(20)
.maxPooledPerRoute(2);
ResteasyJackson2Provider jacksonProvider = new ResteasyJackson2Provider() {};
ObjectMapper objectMapper = new ObjectMapper();
objectMapper.setAnnotationIntrospector(new JacksonAnnotationIntrospector());
jacksonProvider.setMapper(objectMapper);
clientBuilder.register(jacksonProvider, 100);
client = clientBuilder.build();
Keycloak keycloak = KeycloakBuilder.builder()
.serverUrl("http://localhost:8180/auth")
.resteasyClient(client)
.clientId("admin-cli")
.realm("master")
.username("admin")
.password("admin")
.build();
keycloak.realm("master").clients().findAll();
Cheers Felix
5 years, 2 months
User to role and user to group relationships are not imported from LDAP
by Denis Danov
Hi Keycloak users,
Is it possible to extract the relationship between user and role, user and
group, role and group?
In our setup we have LDAP user fenederation and we have configured role and
group mappers in IMPORT mode. However I cannot see the data in keycloak's
DB. Is there additional configuration that needs to be made.
Regards,
Denis
5 years, 2 months