8:25 a.m.
Hello,
While deploying Keycloak 4.5.0.Final in an Openshift environment, using
Mariadb (Galera) as a database produces several exceptions in the logs, all
of them being related to the communication between the Keycloak server and
the database. The access to the Galera server (3 instances) is performed
via a Maxscale proxy. The Galera server, Maxscale (deployment of 3 pods)
and Keycloak (deployment of 2 replicas) are all deployed inside Openshift,
on AWS (1master + 3 workers).
I am hoping you guys can help with fixing these issues.
The errors look like below:
08:40:46,603 WARN
[org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory]
(ConnectionValidator) IJ030027: Destroying connection that is not valid,
due to the following exception: org.mariadb.jdbc.MariaDbConnection@76883993:
java.sql.SQLNonTransientConnectionException: (conn=24) unexpected end of
stream, read 0 bytes from 4 (socket was closed by server)
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:175)
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getException(ExceptionMapper.java:110)
at
org.mariadb.jdbc.MariaDbStatement.executeExceptionEpilogue(MariaDbStatement.java:228)
at
org.mariadb.jdbc.MariaDbStatement.executeInternal(MariaDbStatement.java:334)
at org.mariadb.jdbc.MariaDbStatement.execute(MariaDbStatement.java:386)
at
org.jboss.jca.adapters.jdbc.CheckValidConnectionSQL.isValidConnection(CheckValidConnectionSQL.java:74)
at
org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnectionFactory.isValidConnection(BaseWrapperManagedConnectionFactory.java:1273)
at
org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnectionFactory.getInvalidConnections(BaseWrapperManagedConnectionFactory.java:1086)
at
org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.validateConnections(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:1442)
at
org.jboss.jca.core.connectionmanager.pool.validator.ConnectionValidator$ConnectionValidatorRunner.run(ConnectionValidator.java:277)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLException: unexpected end of stream, read 0 bytes
from 4 (socket was closed by server)
Query is: SELECT 1
at
org.mariadb.jdbc.internal.util.LogQueryTool.exceptionWithQuery(LogQueryTool.java:119)
at
org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:199)
at
org.mariadb.jdbc.MariaDbStatement.executeInternal(MariaDbStatement.java:328)
... 9 more
Caused by: java.io.EOFException: unexpected end of stream, read 0 bytes
from 4 (socket was closed by server)
at
org.mariadb.jdbc.internal.io.input.StandardPacketInputStream.getPacketArray(StandardPacketInputStream.java:239)
at
org.mariadb.jdbc.internal.io.input.StandardPacketInputStream.getPacket(StandardPacketInputStream.java:207)
at
org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.readPacket(AbstractQueryProtocol.java:1347)
at
org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.getResult(AbstractQueryProtocol.java:1328)
at
org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:196)
... 10 more
I suspect that the errors come from the way the jdbc data source is
configured. The mariadb configurations related to connections and wait
timeouts are like below:
max_connections=1000
wait_timeout=180
The second issue I noticed was the following: one of the pods in the
deployments (we deploy 2 replicas of Keycloak) sometimes does not start
correctly because of the following exception, which is still related to the
database connection:
08:13:03,409 ERROR [org.jboss.msc.service.fail] (ServerService Thread Pool
-- 52) MSC000001: Failed to start service
jboss.undertow.deployment.default-server.default-host./auth:
org.jboss.msc.service.StartException in service
jboss.undertow.deployment.default-server.default-host./auth:
java.lang.RuntimeException: RESTEASY003325: Failed to construct public
org.keycloak.services.resources.KeycloakApplication(javax.servlet.ServletContext,org.jboss.resteasy.core.Dispatcher)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:81)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
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)
at org.jboss.threads.JBossThread.run(JBossThread.java:485)
Caused by: java.lang.RuntimeException: RESTEASY003325: Failed to construct
public
org.keycloak.services.resources.KeycloakApplication(javax.servlet.ServletContext,org.jboss.resteasy.core.Dispatcher)
at
org.jboss.resteasy.core.ConstructorInjectorImpl.construct(ConstructorInjectorImpl.java:162)
at
org.jboss.resteasy.spi.ResteasyProviderFactory.createProviderInstance(ResteasyProviderFactory.java:2676)
at
org.jboss.resteasy.spi.ResteasyDeployment.createApplication(ResteasyDeployment.java:361)
at
org.jboss.resteasy.spi.ResteasyDeployment.startInternal(ResteasyDeployment.java:274)
at
org.jboss.resteasy.spi.ResteasyDeployment.start(ResteasyDeployment.java:86)
at
org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.init(ServletContainerDispatcher.java:119)
at
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.init(HttpServletDispatcher.java:36)
at
io.undertow.servlet.core.LifecyleInterceptorInvocation.proceed(LifecyleInterceptorInvocation.java:117)
at
org.wildfly.extension.undertow.security.RunAsLifecycleInterceptor.init(RunAsLifecycleInterceptor.java:78)
at
io.undertow.servlet.core.LifecyleInterceptorInvocation.proceed(LifecyleInterceptorInvocation.java:103)
at
io.undertow.servlet.core.ManagedServlet$DefaultInstanceStrategy.start(ManagedServlet.java:300)
at
io.undertow.servlet.core.ManagedServlet.createServlet(ManagedServlet.java:140)
at
io.undertow.servlet.core.DeploymentManagerImpl$2.call(DeploymentManagerImpl.java:584)
at
io.undertow.servlet.core.DeploymentManagerImpl$2.call(DeploymentManagerImpl.java:555)
at
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:42)
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:1514)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
at
io.undertow.servlet.core.DeploymentManagerImpl.start(DeploymentManagerImpl.java:597)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService.startContext(UndertowDeploymentService.java:97)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:78)
... 8 more
Caused by: java.lang.RuntimeException: Failed to connect to database
at
org.keycloak.connections.jpa.DefaultJpaConnectionProviderFactory.getConnection(DefaultJpaConnectionProviderFactory.java:373)
at
org.keycloak.connections.jpa.updater.liquibase.lock.LiquibaseDBLockProvider.lazyInit(LiquibaseDBLockProvider.java:65)
at
org.keycloak.connections.jpa.updater.liquibase.lock.LiquibaseDBLockProvider.lambda$waitForLock$0(LiquibaseDBLockProvider.java:97)
at
org.keycloak.models.utils.KeycloakModelUtils.suspendJtaTransaction(KeycloakModelUtils.java:611)
at
org.keycloak.connections.jpa.updater.liquibase.lock.LiquibaseDBLockProvider.waitForLock(LiquibaseDBLockProvider.java:95)
at
org.keycloak.services.resources.KeycloakApplication$1.run(KeycloakApplication.java:143)
at
org.keycloak.models.utils.KeycloakModelUtils.runJobInTransaction(KeycloakModelUtils.java:227)
at
org.keycloak.services.resources.KeycloakApplication.<init>(KeycloakApplication.java:136)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at
org.jboss.resteasy.core.ConstructorInjectorImpl.construct(ConstructorInjectorImpl.java:150)
... 31 more
Caused by: java.sql.SQLException: javax.resource.ResourceException:
IJ000453: Unable to get managed connection for
java:jboss/datasources/KeycloakDS
at
org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:146)
at
org.jboss.as.connector.subsystems.datasources.WildFlyDataSource.getConnection(WildFlyDataSource.java:64)
at
org.keycloak.connections.jpa.DefaultJpaConnectionProviderFactory.getConnection(DefaultJpaConnectionProviderFactory.java:367)
... 43 more
Caused by: javax.resource.ResourceException: IJ000453: Unable to get
managed connection for java:jboss/datasources/KeycloakDS
at
org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:690)
at
org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:430)
at
org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:789)
at
org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:138)
... 45 more
Caused by: javax.resource.ResourceException: IJ031084: Unable to create
connection
at
org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.createLocalManagedConnection(LocalManagedConnectionFactory.java:345)
at
org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.getLocalManagedConnection(LocalManagedConnectionFactory.java:352)
at
org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.createManagedConnection(LocalManagedConnectionFactory.java:287)
at
org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.createConnectionEventListener(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:1326)
at
org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.getConnection(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:499)
at
org.jboss.jca.core.connectionmanager.pool.AbstractPool.getSimpleConnection(AbstractPool.java:632)
at
org.jboss.jca.core.connectionmanager.pool.AbstractPool.getConnection(AbstractPool.java:604)
at
org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:624)
... 48 more
Caused by: java.sql.SQLNonTransientConnectionException: could not load
system variables
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:175)
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getException(ExceptionMapper.java:110)
at
org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.connectWithoutProxy(AbstractConnectProtocol.java:1093)
at org.mariadb.jdbc.internal.util.Utils.retrieveProxy(Utils.java:494)
at
org.mariadb.jdbc.MariaDbConnection.newConnection(MariaDbConnection.java:150)
at org.mariadb.jdbc.Driver.connect(Driver.java:86)
at
org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.createLocalManagedConnection(LocalManagedConnectionFactory.java:321)
... 55 more
Caused by: java.sql.SQLNonTransientConnectionException: could not load
system variables
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:175)
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.connException(ExceptionMapper.java:83)
at
org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.readPipelineAdditionalData(AbstractConnectProtocol.java:606)
at
org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.connect(AbstractConnectProtocol.java:477)
at
org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.connectWithoutProxy(AbstractConnectProtocol.java:1089)
... 59 more
Caused by: java.sql.SQLException: Error reading SessionVariables results.
Socket is connected ? true
at
org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.readRequestSessionVariables(AbstractConnectProtocol.java:572)
at
org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.readPipelineAdditionalData(AbstractConnectProtocol.java:603)
... 61 more
The pod is in state running, but it is not ready, as it can be seen below:
oc describe pod keycloak-787795bbcb-qng6j
Name: keycloak-787795bbcb-qng6j
Namespace: frame-2900
Start Time: Thu, 25 Oct 2018 10:03:30 +0200
Labels: application=keycloak
pod-template-hash=3433516676
Annotations: openshift.io/scc=restricted
Status: *Running*
IP: 10.131.0.12
Controlled By: ReplicaSet/keycloak-787795bbcb
Containers:
keycloak:
Container ID:
docker://b703c13a70ffa24f696e08996590b972ec65e6b6041f8d08f50a44372b9e4760
Image: jboss/keycloak
Image ID: docker-pullable://
docker.io/jboss/keycloak@sha256:cb5c24d06f22c51ca193e6d1e930d206ef0b841a745f8e475a08e33f10b38ad4
Ports: 8080/TCP, 8443/TCP
*State: Waiting*
* Reason: CrashLoopBackOff*
Last State: Terminated
Reason: Error
Exit Code: 1
Started: Thu, 25 Oct 2018 10:12:43 +0200
Finished: Thu, 25 Oct 2018 10:13:03 +0200
Ready: False
* Restart Count: 6*
Liveness: http-get http://:8080/auth/realms/master delay=60s
timeout=1s period=10s #success=1 #failure=3
Readiness: http-get http://:8080/auth/realms/master delay=30s
timeout=1s period=10s #success=1 #failure=10
Environment:
KEYCLOAK_USER: BokIm2Kl
KEYCLOAK_PASSWORD: o8QobI0D
PROXY_ADDRESS_FORWARDING: true
DB_VENDOR: MARIADB
JGROUPS_DISCOVERY_PROTOCOL: dns.DNS_PING
JGROUPS_DISCOVERY_PROPERTIES:
dns_query=keycloak.default.svc.cluster.local
DB_ADDR: max-scale
DB_DATABASE: keycloak
DB_PORT: 4408
DB_USER: <set to the key
'keycloakDatabaseUserName' in secret 'qa-complex-secret'>
Optional:
false
DB_PASSWORD: <set to the key
'keycloakDatabaseUserPassword' in secret 'qa-complex-secret'>
Optional:
false
Mounts:
/var/run/secrets/kubernetes.io/serviceaccount from
frame-2900-token-k8cwj (ro)
Conditions:
Type Status
Initialized True
Ready False
PodScheduled True
Volumes:
frame-2900-token-k8cwj:
Type: Secret (a volume populated by a Secret)
SecretName: frame-2900-token-k8cwj
Optional: false
QoS Class: BestEffort
Node-Selectors: node-role.kubernetes.io/compute=true
Tolerations: <none>
Events:
Type Reason Age From
Message
---- ------ ---- ----
-------
Normal Scheduled 11m default-scheduler
Successfully assigned
keycloak-787795bbcb-qng6j to ip-10-0-141-24.eu-west-1.compute.internal
Normal SuccessfulMountVolume 11m kubelet,
ip-10-0-141-24.eu-west-1.compute.internal MountVolume.SetUp succeeded for
volume "frame-2900-token-k8cwj"
Normal Pulled 7m (x4 over 9m) kubelet,
ip-10-0-141-24.eu-west-1.compute.internal Successfully pulled image
"jboss/keycloak"
Normal Created 7m (x4 over 9m) kubelet,
ip-10-0-141-24.eu-west-1.compute.internal Created container
Normal Started 7m (x4 over 9m) kubelet,
ip-10-0-141-24.eu-west-1.compute.internal Started container
Normal Pulling 6m (x5 over 10m) kubelet,
ip-10-0-141-24.eu-west-1.compute.internal pulling image "jboss/keycloak"
Warning BackOff 53s (x31 over 8m) kubelet,
ip-10-0-141-24.eu-west-1.compute.internal Back-off restarting failed
container
The pod is restarted several times it seems, but it does not start
correctly. I deleted the pod and it was recreated automatically by
Openshift and the new pod started correctly.
Then, there is a third issue that I've encountered while trying to login
into the deployed application. While entering some wrong credentials I got
an error page and noticed in the logs that there is still a database
connection error:
08:18:12,405 WARN [org.keycloak.services] (default task-2)
KC-SERVICES0013: Failed authentication:
javax.persistence.PersistenceException:
org.hibernate.exception.JDBCConnectionException: could not extract ResultSet
at
org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1692)
at
org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1602)
at org.hibernate.jpa.internal.QueryImpl.getResultList(QueryImpl.java:492)
at
org.keycloak.models.jpa.JpaUserProvider.getUserByUsername(JpaUserProvider.java:526)
at
org.keycloak.storage.UserStorageManager.getUserByUsername(UserStorageManager.java:390)
at
org.keycloak.models.cache.infinispan.UserCacheSession.getUserByUsername(UserCacheSession.java:253)
at
org.keycloak.models.utils.KeycloakModelUtils.findUserByNameOrEmail(KeycloakModelUtils.java:213)
at
org.keycloak.authentication.authenticators.browser.AbstractUsernameFormAuthenticator.validateUserAndPassword(AbstractUsernameFormAuthenticator.java:153)
at
org.keycloak.authentication.authenticators.browser.UsernamePasswordForm.validateForm(UsernamePasswordForm.java:55)
at
org.keycloak.authentication.authenticators.browser.UsernamePasswordForm.action(UsernamePasswordForm.java:48)
at
org.keycloak.authentication.DefaultAuthenticationFlow.processAction(DefaultAuthenticationFlow.java:113)
at
org.keycloak.authentication.DefaultAuthenticationFlow.processAction(DefaultAuthenticationFlow.java:97)
at
org.keycloak.authentication.AuthenticationProcessor.authenticationAction(AuthenticationProcessor.java:873)
at
org.keycloak.services.resources.LoginActionsService.processFlow(LoginActionsService.java:292)
at
org.keycloak.services.resources.LoginActionsService.processAuthentication(LoginActionsService.java:263)
at
org.keycloak.services.resources.LoginActionsService.authenticate(LoginActionsService.java:259)
at
org.keycloak.services.resources.LoginActionsService.authenticateForm(LoginActionsService.java:320)
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:510)
at
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:401)
at
org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$0(ResourceMethodInvoker.java:365)
at
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:361)
at
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:367)
at
org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:339)
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:441)
at
org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:231)
at
org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:137)
at
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:361)
at
org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:140)
at
org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:217)
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:790)
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:1514)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
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: org.hibernate.exception.JDBCConnectionException: could not
extract ResultSet
at
org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:48)
at
org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
at
org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:111)
at
org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:97)
at
org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:79)
at org.hibernate.loader.Loader.getResultSet(Loader.java:2122)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1905)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1881)
at org.hibernate.loader.Loader.doQuery(Loader.java:925)
at
org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:342)
at org.hibernate.loader.Loader.doList(Loader.java:2622)
at org.hibernate.loader.Loader.doList(Loader.java:2605)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2434)
at org.hibernate.loader.Loader.list(Loader.java:2429)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:501)
at
org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:370)
at
org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:216)
at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1339)
at org.hibernate.internal.QueryImpl.list(QueryImpl.java:87)
at org.hibernate.jpa.internal.QueryImpl.list(QueryImpl.java:606)
at org.hibernate.jpa.internal.QueryImpl.getResultList(QueryImpl.java:483)
... 83 more
Caused by: java.sql.SQLNonTransientConnectionException: (conn=476)
Connection is closed
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:175)
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getException(ExceptionMapper.java:110)
at
org.mariadb.jdbc.MariaDbStatement.executeExceptionEpilogue(MariaDbStatement.java:228)
at
org.mariadb.jdbc.MariaDbPreparedStatementClient.executeInternal(MariaDbPreparedStatementClient.java:216)
at
org.mariadb.jdbc.MariaDbPreparedStatementClient.execute(MariaDbPreparedStatementClient.java:150)
at org.mariadb.jdb
c.MariaDbPreparedStatementClient.executeQuery(MariaDbPreparedStatementClient.java:164)
at
org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:504)
at
org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:70)
... 99 more
Caused by: java.sql.SQLException: Connection is closed
at
org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.cmdPrologue(AbstractQueryProtocol.java:1711)
at
org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:237)
at
org.mariadb.jdbc.MariaDbPreparedStatementClient.executeInternal(MariaDbPreparedStatementClient.java:209)
... 103 more
After a couple of seconds, the issue dissapeared, probably because Keycloak
was able to get a valid connection from the connection pool.
Thanks in advance for your help.
Greetings,
Cristi
6:17 a.m.
Hi,
I had the same problem with Keycloak 4.8.3 Docker Image and Galera Cluster. The problem
seems to be in MariaDB Conncetor/J since version 2.2.5. With older versions it worked and
with newer versions I need to change the connection-url to sth like this:
jdbc:mariadb:failover://${SOME_URL}/${DB}
jdbc:mariadb:sequential://${SOME_URL}/${DB}
Unfortunately it was not possible to change the protocol part of that URL via Docker env
variables, so I had to extend the image with some custom CLI scripts.
Cheers,
sascha
________________________________
Von: keycloak-user-bounces(a)lists.jboss.org <keycloak-user-bounces(a)lists.jboss.org>
im Auftrag von Cristi Cioriia <cristi.cioriia(a)gmail.com>
Gesendet: Freitag, 26. Oktober 2018 15:25:09
An: keycloak-user(a)lists.jboss.org
Betreff: [keycloak-user] Deploying Keycloak on Openshift with MariaDB persistence produces
errors in logs
Hello,
While deploying Keycloak 4.5.0.Final in an Openshift environment, using
Mariadb (Galera) as a database produces several exceptions in the logs, all
of them being related to the communication between the Keycloak server and
the database. The access to the Galera server (3 instances) is performed
via a Maxscale proxy. The Galera server, Maxscale (deployment of 3 pods)
and Keycloak (deployment of 2 replicas) are all deployed inside Openshift,
on AWS (1master + 3 workers).
I am hoping you guys can help with fixing these issues.
The errors look like below:
08:40:46,603 WARN
[org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory]
(ConnectionValidator) IJ030027: Destroying connection that is not valid,
due to the following exception: org.mariadb.jdbc.MariaDbConnection@76883993:
java.sql.SQLNonTransientConnectionException: (conn=24) unexpected end of
stream, read 0 bytes from 4 (socket was closed by server)
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:175)
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getException(ExceptionMapper.java:110)
at
org.mariadb.jdbc.MariaDbStatement.executeExceptionEpilogue(MariaDbStatement.java:228)
at
org.mariadb.jdbc.MariaDbStatement.executeInternal(MariaDbStatement.java:334)
at org.mariadb.jdbc.MariaDbStatement.execute(MariaDbStatement.java:386)
at
org.jboss.jca.adapters.jdbc.CheckValidConnectionSQL.isValidConnection(CheckValidConnectionSQL.java:74)
at
org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnectionFactory.isValidConnection(BaseWrapperManagedConnectionFactory.java:1273)
at
org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnectionFactory.getInvalidConnections(BaseWrapperManagedConnectionFactory.java:1086)
at
org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.validateConnections(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:1442)
at
org.jboss.jca.core.connectionmanager.pool.validator.ConnectionValidator$ConnectionValidatorRunner.run(ConnectionValidator.java:277)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLException: unexpected end of stream, read 0 bytes
from 4 (socket was closed by server)
Query is: SELECT 1
at
org.mariadb.jdbc.internal.util.LogQueryTool.exceptionWithQuery(LogQueryTool.java:119)
at
org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:199)
at
org.mariadb.jdbc.MariaDbStatement.executeInternal(MariaDbStatement.java:328)
... 9 more
Caused by: java.io.EOFException: unexpected end of stream, read 0 bytes
from 4 (socket was closed by server)
at
org.mariadb.jdbc.internal.io.input.StandardPacketInputStream.getPacketArray(StandardPacketInputStream.java:239)
at
org.mariadb.jdbc.internal.io.input.StandardPacketInputStream.getPacket(StandardPacketInputStream.java:207)
at
org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.readPacket(AbstractQueryProtocol.java:1347)
at
org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.getResult(AbstractQueryProtocol.java:1328)
at
org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:196)
... 10 more
I suspect that the errors come from the way the jdbc data source is
configured. The mariadb configurations related to connections and wait
timeouts are like below:
max_connections=1000
wait_timeout=180
The second issue I noticed was the following: one of the pods in the
deployments (we deploy 2 replicas of Keycloak) sometimes does not start
correctly because of the following exception, which is still related to the
database connection:
08:13:03,409 ERROR [org.jboss.msc.service.fail] (ServerService Thread Pool
-- 52) MSC000001: Failed to start service
jboss.undertow.deployment.default-server.default-host./auth:
org.jboss.msc.service.StartException in service
jboss.undertow.deployment.default-server.default-host./auth:
java.lang.RuntimeException: RESTEASY003325: Failed to construct public
org.keycloak.services.resources.KeycloakApplication(javax.servlet.ServletContext,org.jboss.resteasy.core.Dispatcher)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:81)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
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)
at org.jboss.threads.JBossThread.run(JBossThread.java:485)
Caused by: java.lang.RuntimeException: RESTEASY003325: Failed to construct
public
org.keycloak.services.resources.KeycloakApplication(javax.servlet.ServletContext,org.jboss.resteasy.core.Dispatcher)
at
org.jboss.resteasy.core.ConstructorInjectorImpl.construct(ConstructorInjectorImpl.java:162)
at
org.jboss.resteasy.spi.ResteasyProviderFactory.createProviderInstance(ResteasyProviderFactory.java:2676)
at
org.jboss.resteasy.spi.ResteasyDeployment.createApplication(ResteasyDeployment.java:361)
at
org.jboss.resteasy.spi.ResteasyDeployment.startInternal(ResteasyDeployment.java:274)
at
org.jboss.resteasy.spi.ResteasyDeployment.start(ResteasyDeployment.java:86)
at
org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.init(ServletContainerDispatcher.java:119)
at
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.init(HttpServletDispatcher.java:36)
at
io.undertow.servlet.core.LifecyleInterceptorInvocation.proceed(LifecyleInterceptorInvocation.java:117)
at
org.wildfly.extension.undertow.security.RunAsLifecycleInterceptor.init(RunAsLifecycleInterceptor.java:78)
at
io.undertow.servlet.core.LifecyleInterceptorInvocation.proceed(LifecyleInterceptorInvocation.java:103)
at
io.undertow.servlet.core.ManagedServlet$DefaultInstanceStrategy.start(ManagedServlet.java:300)
at
io.undertow.servlet.core.ManagedServlet.createServlet(ManagedServlet.java:140)
at
io.undertow.servlet.core.DeploymentManagerImpl$2.call(DeploymentManagerImpl.java:584)
at
io.undertow.servlet.core.DeploymentManagerImpl$2.call(DeploymentManagerImpl.java:555)
at
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:42)
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:1514)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
at
io.undertow.servlet.core.DeploymentManagerImpl.start(DeploymentManagerImpl.java:597)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService.startContext(UndertowDeploymentService.java:97)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentService$1.run(UndertowDeploymentService.java:78)
... 8 more
Caused by: java.lang.RuntimeException: Failed to connect to database
at
org.keycloak.connections.jpa.DefaultJpaConnectionProviderFactory.getConnection(DefaultJpaConnectionProviderFactory.java:373)
at
org.keycloak.connections.jpa.updater.liquibase.lock.LiquibaseDBLockProvider.lazyInit(LiquibaseDBLockProvider.java:65)
at
org.keycloak.connections.jpa.updater.liquibase.lock.LiquibaseDBLockProvider.lambda$waitForLock$0(LiquibaseDBLockProvider.java:97)
at
org.keycloak.models.utils.KeycloakModelUtils.suspendJtaTransaction(KeycloakModelUtils.java:611)
at
org.keycloak.connections.jpa.updater.liquibase.lock.LiquibaseDBLockProvider.waitForLock(LiquibaseDBLockProvider.java:95)
at
org.keycloak.services.resources.KeycloakApplication$1.run(KeycloakApplication.java:143)
at
org.keycloak.models.utils.KeycloakModelUtils.runJobInTransaction(KeycloakModelUtils.java:227)
at
org.keycloak.services.resources.KeycloakApplication.<init>(KeycloakApplication.java:136)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at
org.jboss.resteasy.core.ConstructorInjectorImpl.construct(ConstructorInjectorImpl.java:150)
... 31 more
Caused by: java.sql.SQLException: javax.resource.ResourceException:
IJ000453: Unable to get managed connection for
java:jboss/datasources/KeycloakDS
at
org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:146)
at
org.jboss.as.connector.subsystems.datasources.WildFlyDataSource.getConnection(WildFlyDataSource.java:64)
at
org.keycloak.connections.jpa.DefaultJpaConnectionProviderFactory.getConnection(DefaultJpaConnectionProviderFactory.java:367)
... 43 more
Caused by: javax.resource.ResourceException: IJ000453: Unable to get
managed connection for java:jboss/datasources/KeycloakDS
at
org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:690)
at
org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:430)
at
org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:789)
at
org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:138)
... 45 more
Caused by: javax.resource.ResourceException: IJ031084: Unable to create
connection
at
org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.createLocalManagedConnection(LocalManagedConnectionFactory.java:345)
at
org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.getLocalManagedConnection(LocalManagedConnectionFactory.java:352)
at
org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.createManagedConnection(LocalManagedConnectionFactory.java:287)
at
org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.createConnectionEventListener(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:1326)
at
org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.getConnection(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:499)
at
org.jboss.jca.core.connectionmanager.pool.AbstractPool.getSimpleConnection(AbstractPool.java:632)
at
org.jboss.jca.core.connectionmanager.pool.AbstractPool.getConnection(AbstractPool.java:604)
at
org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:624)
... 48 more
Caused by: java.sql.SQLNonTransientConnectionException: could not load
system variables
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:175)
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getException(ExceptionMapper.java:110)
at
org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.connectWithoutProxy(AbstractConnectProtocol.java:1093)
at org.mariadb.jdbc.internal.util.Utils.retrieveProxy(Utils.java:494)
at
org.mariadb.jdbc.MariaDbConnection.newConnection(MariaDbConnection.java:150)
at org.mariadb.jdbc.Driver.connect(Driver.java:86)
at
org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.createLocalManagedConnection(LocalManagedConnectionFactory.java:321)
... 55 more
Caused by: java.sql.SQLNonTransientConnectionException: could not load
system variables
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:175)
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.connException(ExceptionMapper.java:83)
at
org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.readPipelineAdditionalData(AbstractConnectProtocol.java:606)
at
org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.connect(AbstractConnectProtocol.java:477)
at
org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.connectWithoutProxy(AbstractConnectProtocol.java:1089)
... 59 more
Caused by: java.sql.SQLException: Error reading SessionVariables results.
Socket is connected ? true
at
org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.readRequestSessionVariables(AbstractConnectProtocol.java:572)
at
org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.readPipelineAdditionalData(AbstractConnectProtocol.java:603)
... 61 more
The pod is in state running, but it is not ready, as it can be seen below:
oc describe pod keycloak-787795bbcb-qng6j
Name: keycloak-787795bbcb-qng6j
Namespace: frame-2900
Start Time: Thu, 25 Oct 2018 10:03:30 +0200
Labels: application=keycloak
pod-template-hash=3433516676
Annotations: openshift.io/scc=restricted
Status: *Running*
IP: 10.131.0.12
Controlled By: ReplicaSet/keycloak-787795bbcb
Containers:
keycloak:
Container ID:
docker://b703c13a70ffa24f696e08996590b972ec65e6b6041f8d08f50a44372b9e4760
Image: jboss/keycloak
Image ID: docker-pullable://
docker.io/jboss/keycloak@sha256:cb5c24d06f22c51ca193e6d1e930d206ef0b841a745f8e475a08e33f10b38ad4
Ports: 8080/TCP, 8443/TCP
*State: Waiting*
* Reason: CrashLoopBackOff*
Last State: Terminated
Reason: Error
Exit Code: 1
Started: Thu, 25 Oct 2018 10:12:43 +0200
Finished: Thu, 25 Oct 2018 10:13:03 +0200
Ready: False
* Restart Count: 6*
Liveness: http-get http://:8080/auth/realms/master delay=60s
timeout=1s period=10s #success=1 #failure=3
Readiness: http-get http://:8080/auth/realms/master delay=30s
timeout=1s period=10s #success=1 #failure=10
Environment:
KEYCLOAK_USER: BokIm2Kl
KEYCLOAK_PASSWORD: o8QobI0D
PROXY_ADDRESS_FORWARDING: true
DB_VENDOR: MARIADB
JGROUPS_DISCOVERY_PROTOCOL: dns.DNS_PING
JGROUPS_DISCOVERY_PROPERTIES:
dns_query=keycloak.default.svc.cluster.local
DB_ADDR: max-scale
DB_DATABASE: keycloak
DB_PORT: 4408
DB_USER: <set to the key
'keycloakDatabaseUserName' in secret 'qa-complex-secret'>
Optional:
false
DB_PASSWORD: <set to the key
'keycloakDatabaseUserPassword' in secret 'qa-complex-secret'>
Optional:
false
Mounts:
/var/run/secrets/kubernetes.io/serviceaccount from
frame-2900-token-k8cwj (ro)
Conditions:
Type Status
Initialized True
Ready False
PodScheduled True
Volumes:
frame-2900-token-k8cwj:
Type: Secret (a volume populated by a Secret)
SecretName: frame-2900-token-k8cwj
Optional: false
QoS Class: BestEffort
Node-Selectors: node-role.kubernetes.io/compute=true
Tolerations: <none>
Events:
Type Reason Age From
Message
---- ------ ---- ----
-------
Normal Scheduled 11m default-scheduler
Successfully assigned
keycloak-787795bbcb-qng6j to ip-10-0-141-24.eu-west-1.compute.internal
Normal SuccessfulMountVolume 11m kubelet,
ip-10-0-141-24.eu-west-1.compute.internal MountVolume.SetUp succeeded for
volume "frame-2900-token-k8cwj"
Normal Pulled 7m (x4 over 9m) kubelet,
ip-10-0-141-24.eu-west-1.compute.internal Successfully pulled image
"jboss/keycloak"
Normal Created 7m (x4 over 9m) kubelet,
ip-10-0-141-24.eu-west-1.compute.internal Created container
Normal Started 7m (x4 over 9m) kubelet,
ip-10-0-141-24.eu-west-1.compute.internal Started container
Normal Pulling 6m (x5 over 10m) kubelet,
ip-10-0-141-24.eu-west-1.compute.internal pulling image "jboss/keycloak"
Warning BackOff 53s (x31 over 8m) kubelet,
ip-10-0-141-24.eu-west-1.compute.internal Back-off restarting failed
container
The pod is restarted several times it seems, but it does not start
correctly. I deleted the pod and it was recreated automatically by
Openshift and the new pod started correctly.
Then, there is a third issue that I've encountered while trying to login
into the deployed application. While entering some wrong credentials I got
an error page and noticed in the logs that there is still a database
connection error:
08:18:12,405 WARN [org.keycloak.services] (default task-2)
KC-SERVICES0013: Failed authentication:
javax.persistence.PersistenceException:
org.hibernate.exception.JDBCConnectionException: could not extract ResultSet
at
org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1692)
at
org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1602)
at org.hibernate.jpa.internal.QueryImpl.getResultList(QueryImpl.java:492)
at
org.keycloak.models.jpa.JpaUserProvider.getUserByUsername(JpaUserProvider.java:526)
at
org.keycloak.storage.UserStorageManager.getUserByUsername(UserStorageManager.java:390)
at
org.keycloak.models.cache.infinispan.UserCacheSession.getUserByUsername(UserCacheSession.java:253)
at
org.keycloak.models.utils.KeycloakModelUtils.findUserByNameOrEmail(KeycloakModelUtils.java:213)
at
org.keycloak.authentication.authenticators.browser.AbstractUsernameFormAuthenticator.validateUserAndPassword(AbstractUsernameFormAuthenticator.java:153)
at
org.keycloak.authentication.authenticators.browser.UsernamePasswordForm.validateForm(UsernamePasswordForm.java:55)
at
org.keycloak.authentication.authenticators.browser.UsernamePasswordForm.action(UsernamePasswordForm.java:48)
at
org.keycloak.authentication.DefaultAuthenticationFlow.processAction(DefaultAuthenticationFlow.java:113)
at
org.keycloak.authentication.DefaultAuthenticationFlow.processAction(DefaultAuthenticationFlow.java:97)
at
org.keycloak.authentication.AuthenticationProcessor.authenticationAction(AuthenticationProcessor.java:873)
at
org.keycloak.services.resources.LoginActionsService.processFlow(LoginActionsService.java:292)
at
org.keycloak.services.resources.LoginActionsService.processAuthentication(LoginActionsService.java:263)
at
org.keycloak.services.resources.LoginActionsService.authenticate(LoginActionsService.java:259)
at
org.keycloak.services.resources.LoginActionsService.authenticateForm(LoginActionsService.java:320)
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:510)
at
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:401)
at
org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$0(ResourceMethodInvoker.java:365)
at
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:361)
at
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:367)
at
org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:339)
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:441)
at
org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:231)
at
org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:137)
at
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:361)
at
org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:140)
at
org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:217)
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:790)
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:1514)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
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: org.hibernate.exception.JDBCConnectionException: could not
extract ResultSet
at
org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:48)
at
org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
at
org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:111)
at
org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:97)
at
org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:79)
at org.hibernate.loader.Loader.getResultSet(Loader.java:2122)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1905)
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1881)
at org.hibernate.loader.Loader.doQuery(Loader.java:925)
at
org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:342)
at org.hibernate.loader.Loader.doList(Loader.java:2622)
at org.hibernate.loader.Loader.doList(Loader.java:2605)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2434)
at org.hibernate.loader.Loader.list(Loader.java:2429)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:501)
at
org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:370)
at
org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:216)
at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1339)
at org.hibernate.internal.QueryImpl.list(QueryImpl.java:87)
at org.hibernate.jpa.internal.QueryImpl.list(QueryImpl.java:606)
at org.hibernate.jpa.internal.QueryImpl.getResultList(QueryImpl.java:483)
... 83 more
Caused by: java.sql.SQLNonTransientConnectionException: (conn=476)
Connection is closed
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:175)
at
org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getException(ExceptionMapper.java:110)
at
org.mariadb.jdbc.MariaDbStatement.executeExceptionEpilogue(MariaDbStatement.java:228)
at
org.mariadb.jdbc.MariaDbPreparedStatementClient.executeInternal(MariaDbPreparedStatementClient.java:216)
at
org.mariadb.jdbc.MariaDbPreparedStatementClient.execute(MariaDbPreparedStatementClient.java:150)
at org.mariadb.jdb
c.MariaDbPreparedStatementClient.executeQuery(MariaDbPreparedStatementClient.java:164)
at
org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:504)
at
org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:70)
... 99 more
Caused by: java.sql.SQLException: Connection is closed
at
org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.cmdPrologue(AbstractQueryProtocol.java:1711)
at
org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:237)
at
org.mariadb.jdbc.MariaDbPreparedStatementClient.executeInternal(MariaDbPreparedStatementClient.java:209)
... 103 more
After a couple of seconds, the issue dissapeared, probably because Keycloak
was able to get a valid connection from the connection pool.
Thanks in advance for your help.
Greetings,
Cristi
_______________________________________________
keycloak-user mailing list
keycloak-user(a)lists.jboss.org
https://lists.jboss.org/mailman/listinfo/keycloak-user
2165
days inactive
2269
days old
1 comments
2 participants
participants (2)
-
Cristi Cioriia -
Skorupa, Sascha