7:05 p.m.
Hi,
I've verified this problem with keycloak latest version as well as v4.8.x,
using broker only works with google, with other social identify providers,
all throws the same error 'Unexpected error when authenticating with
identity provider' to the browser and in server.log:
10:46:59,838 ERROR
[org.keycloak.broker.oidc.AbstractOAuth2IdentityProvider] (default task-2)
Failed to make identity provider oauth callback:
javax.net.ssl.SSLException: Received fatal alert: protocol_version
at com.ibm.jsse2.k.a(k.java:32)
at com.ibm.jsse2.k.a(k.java:37)
at com.ibm.jsse2.av.b(av.java:549)
at com.ibm.jsse2.av.a(av.java:715)
at com.ibm.jsse2.av.i(av.java:574)
at com.ibm.jsse2.av.a(av.java:280)
at com.ibm.jsse2.av.startHandshake(av.java:431)
at
org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:396)
at
org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:355)
at
org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)
at
org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:373)
at
org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:381)
at
org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:237)
at
org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
at
org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
That happens after the correct credentials being put in. So far, I've
tested:
- linkedin
- facebook
- microsoft
- github
The error almost suggest the error is with incorrect TLS version. To
troubleshoot, I sniffed network packets, comparing Google with non-working
providers (ex, LInkedIn).
Interesting thing found out was that, the keycloak instance is hosted
behind a proxy, when authenticating with external providers, all
communication shall go through proxy,
in google's case it went well and communication was successful, however
with Linkedin for example, after username/password successfully
authenticated, the backend keycloak instance all in sudden start to talk to
LinkedIn server itself instead of going through proxy. Of course the
communication will fail and error returned.
Can anyone advice?
PS: keycloak mailing list seems to have trouble with google email, I
apologize in advance if the reply is delayed or resent multiple times.
Thanks!
Mizuki
10:33 p.m.
Just a comment:
I do not want to unnecessarily complicate the case by involving proxy.
From the packets flow, it seems like Keycloak started initiating
communication with those social providers using TLSv1 (after password was
submitted and possible during code-for-token stage), any reasons triggered
this or any work-arounds? is it because the social providers are using
TLSv1?
Cheers.
Mizuki
On Tue, Apr 2, 2019 at 1:05 PM mizuki <mizuki0621(a)gmail.com> wrote:
7:25 p.m.
Further debugging logs from keycloak when failed with LinkedIn, while the
connection with google.com is successful using the same TLSv1 protocol +
Cipher suites.
2019-04-03 13:07:41,444 DEBUG [io.undertow.request] (default I/O-5) Matched
prefix path /auth for path /auth/realms/SDCC1/broker/linkedin/endpoint
2019-04-03 13:07:41,445 DEBUG [io.undertow.request.security] (default
task-4) Attempting to authenticate
/auth/realms/SDCC1/broker/linkedin/endpoint, authentication required: false
2019-04-03 13:07:41,445 DEBUG [io.undertow.request.security] (default
task-4) Authentication outcome was NOT_ATTEMPTED with method
io.undertow.security.impl.CachedAuthenticatedSessionMechanism@11511aa9 for
/auth/realms/SDCC1/broker/linkedin/endpoint
2019-04-03 13:07:41,445 DEBUG [io.undertow.request.security] (default
task-4) Authentication result was ATTEMPTED for
/auth/realms/SDCC1/broker/linkedin/endpoint
2019-04-03 13:07:41,446 DEBUG
[org.keycloak.transaction.JtaTransactionWrapper] (default task-4) new
JtaTransactionWrapper
2019-04-03 13:07:41,446 DEBUG
[org.keycloak.transaction.JtaTransactionWrapper] (default task-4) was
existing? false
2019-04-03 13:07:41,447 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n]
(default task-4) RESTEASY002315: PathInfo:
/realms/SDCC1/broker/linkedin/endpoint
2019-04-03 13:07:41,450 DEBUG [org.jboss.resteasy.plugins.validation.i18n]
(default task-4) RESTEASY008510: ResteasyCdiExtension is on the classpath.
2019-04-03 13:07:41,453 DEBUG
[org.apache.http.client.protocol.RequestAuthCache] (default task-4) Auth
cache not set in the context
2019-04-03 13:07:41,454 DEBUG
[org.apache.http.impl.conn.PoolingHttpClientConnectionManager] (default
task-4) Connection request: [route: {s}->https://www.linkedin.com:443][total
kept alive: 2; route allocated: 0 of 64; total allocated: 2 of 128]
2019-04-03 13:07:41,454 DEBUG
[org.apache.http.impl.conn.PoolingHttpClientConnectionManager] (default
task-4) Connection leased: [id: 2][route:
{s}->https://www.linkedin.com:443][total
kept alive: 2; route allocated: 1 of 64; total allocated: 3 of 128]
2019-04-03 13:07:41,454 DEBUG
[org.apache.http.impl.execchain.MainClientExec] (default task-4) Opening
connection {s}->https://www.linkedin.com:443
2019-04-03 13:07:41,468 DEBUG
[org.apache.http.impl.conn.DefaultHttpClientConnectionOperator] (default
task-4) Connecting to www.linkedin.com/108.174.11.17:443
2019-04-03 13:07:41,468 DEBUG
[org.apache.http.conn.ssl.SSLConnectionSocketFactory] (default task-4)
Connecting socket to www.linkedin.com/108.174.11.17:443 with timeout 0
2019-04-03 13:07:41,500 DEBUG
[org.apache.http.conn.ssl.SSLConnectionSocketFactory] (default task-4)
Enabled protocols: [TLSv1]
2019-04-03 13:07:41,500 DEBUG
[org.apache.http.conn.ssl.SSLConnectionSocketFactory] (default task-4)
Enabled cipher suites:[TLS_EMPTY_RENEGOTIATION_INFO_SCSV,
SSL_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384,
SSL_ECDHE_RSA_WITH_AES_256_CBC_SHA384, SSL_RSA_WITH_AES_256_CBC_SHA256,
SSL_ECDH_ECDSA_WITH_AES_256_CBC_SHA384,
SSL_ECDH_RSA_WITH_AES_256_CBC_SHA384, SSL_DHE_RSA_WITH_AES_256_CBC_SHA256,
SSL_DHE_DSS_WITH_AES_256_CBC_SHA256, SSL_ECDHE_ECDSA_WITH_AES_256_CBC_SHA,
SSL_ECDHE_RSA_WITH_AES_256_CBC_SHA, SSL_RSA_WITH_AES_256_CBC_SHA,
SSL_ECDH_ECDSA_WITH_AES_256_CBC_SHA, SSL_ECDH_RSA_WITH_AES_256_CBC_SHA,
SSL_DHE_RSA_WITH_AES_256_CBC_SHA, SSL_DHE_DSS_WITH_AES_256_CBC_SHA,
SSL_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256,
SSL_ECDHE_RSA_WITH_AES_128_CBC_SHA256, SSL_RSA_WITH_AES_128_CBC_SHA256,
SSL_ECDH_ECDSA_WITH_AES_128_CBC_SHA256,
SSL_ECDH_RSA_WITH_AES_128_CBC_SHA256, SSL_DHE_RSA_WITH_AES_128_CBC_SHA256,
SSL_DHE_DSS_WITH_AES_128_CBC_SHA256, SSL_ECDHE_ECDSA_WITH_AES_128_CBC_SHA,
SSL_ECDHE_RSA_WITH_AES_128_CBC_SHA, SSL_RSA_WITH_AES_128_CBC_SHA,
SSL_ECDH_ECDSA_WITH_AES_128_CBC_SHA, SSL_ECDH_RSA_WITH_AES_128_CBC_SHA,
SSL_DHE_RSA_WITH_AES_128_CBC_SHA, SSL_DHE_DSS_WITH_AES_128_CBC_SHA,
SSL_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,
SSL_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,
SSL_ECDHE_RSA_WITH_AES_256_GCM_SHA384, SSL_RSA_WITH_AES_256_GCM_SHA384,
SSL_ECDH_ECDSA_WITH_AES_256_GCM_SHA384,
SSL_ECDH_RSA_WITH_AES_256_GCM_SHA384, SSL_DHE_DSS_WITH_AES_256_GCM_SHA384,
SSL_DHE_RSA_WITH_AES_256_GCM_SHA384, SSL_ECDHE_RSA_WITH_AES_128_GCM_SHA256,
SSL_RSA_WITH_AES_128_GCM_SHA256, SSL_ECDH_ECDSA_WITH_AES_128_GCM_SHA256,
SSL_ECDH_RSA_WITH_AES_128_GCM_SHA256, SSL_DHE_RSA_WITH_AES_128_GCM_SHA256,
SSL_DHE_DSS_WITH_AES_128_GCM_SHA256]
*2019-04-03 13:07:41,500 DEBUG
[org.apache.http.conn.ssl.SSLConnectionSocketFactory] (default task-4)
Starting handshake*
*2019-04-03 13:07:41,544 DEBUG
[org.apache.http.impl.conn.DefaultManagedHttpClientConnection] (default
task-4) http-outgoing-2: Shutdown connection*
2019-04-03 13:07:41,545 DEBUG
[org.apache.http.impl.execchain.MainClientExec] (default task-4) Connection
discarded
2019-04-03 13:07:41,545 DEBUG
[org.apache.http.impl.conn.PoolingHttpClientConnectionManager] (default
task-4) Connection released: [id: 2][route:
{s}->https://www.linkedin.com:443][total kept alive: 2; route allocated: 0
of 64; total allocated: 2 of 128]
2019-04-03 13:07:41,545 ERROR
[org.keycloak.broker.oidc.AbstractOAuth2IdentityProvider] (default task-4)
Failed to make identity provider oauth callback:
javax.net.ssl.SSLException: Received fatal alert: protocol_version
at com.ibm.jsse2.k.a(k.java:32)
at com.ibm.jsse2.k.a(k.java:37)
at com.ibm.jsse2.av.b(av.java:549)
at com.ibm.jsse2.k.a(k.java:37)
at com.ibm.jsse2.av.b(av.java:549)
at com.ibm.jsse2.av.a(av.java:715)
at com.ibm.jsse2.av.i(av.java:574)
at com.ibm.jsse2.av.a(av.java:280)
at com.ibm.jsse2.av.startHandshake(av.java:431)
at
org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:396)
at
org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:355)
at
org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)
at
org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:373)
at
org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:381)
at
org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:237)
at
org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
at
org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
at
org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
at
org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
at
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
at
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
at
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
at
org.keycloak.broker.provider.util.SimpleHttp.makeRequest(SimpleHttp.java:199)
at
org.keycloak.broker.provider.util.SimpleHttp.asResponse(SimpleHttp.java:163)
at
org.keycloak.broker.provider.util.SimpleHttp.asString(SimpleHttp.java:155)
at
org.keycloak.broker.oidc.AbstractOAuth2IdentityProvider$Endpoint.authResponse(AbstractOAuth2IdentityProvider.java:418)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:90)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
at java.lang.reflect.Method.invoke(Method.java:508)
at
org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:139)
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.ResourceMethodInvoker$$Lambda$815.00000000811AC040.get(Unknown
Source)
at
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:355)
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:439)
Mizuki
On Tue, Apr 2, 2019 at 4:33 PM mizuki <mizuki0621(a)gmail.com> wrote:
2170
days inactive
2172
days old
3 comments
1 participants
participants (1)
-
mizuki