4:09 a.m.
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: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:...
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
7:13 a.m.
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(a)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@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
--
"Ever tried. Ever failed. No matter. Try Again. Fail again. Fail better."
- Samuel Beckett
8:30 a.m.
Hi,
On Wed, Feb 06, 2019 at 02:13:46PM +0100, Luis Rodríguez Fernández wrote:
May I ask you what is the client implementation? For my dev
environment,
Thanks for the answer! :-) It is a client built with OpenSAML.
The signature created by it, according to Oxygen12, is valid
(by validing the Base64 encoded SAML Authn Request obtained from WireShark).
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.
> <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
We do use this C14n algorithm already ...
Uhmm... can it be that the received SOAP is passed through a DocumentBUilderFactory using
Jaxb (thus adding
fake namespaces) or Transforms with some level on indentation that breaks the signature,
in the version 4.8.3?
Thanks!
2165
days inactive
2166
days old
2 comments
2 participants
participants (2)
-
Luis Rodríguez Fernández -
max＠mascanc.net