Apicurio-studio: Got database connection closed exception

Created on 23 Apr 2019 · 7Comments · Source: Apicurio/apicurio-studio

Hi,
While we are trying apicurio, we got database connction closed exception from time to time.
We've tried postgresql and mysql, both databases have this problem, the first version we installed is 0.2.25, we have upgraded to 0.2.26, this problem still exists.
We are running apicruio in k8s use images from dockerhub.

Any ideas? Thanks.


io.apicurio.hub.core.exceptions.ServerError: Unexpected server error
    at io.apicurio.hub.api.rest.impl.DesignsResource.listDesigns(DesignsResource.java:167)
    at io.apicurio.hub.api.rest.impl.DesignsResource$Proxy$_$$_WeldClientProxy.listDesigns(Unknown Source)
    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: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.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.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:310)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:439)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:229)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:135)
    at org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:355)
    at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:138)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:215)
    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 io.apicurio.hub.api.security.KeycloakAuthenticationFilter.doFilter(KeycloakAuthenticationFilter.java:72)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at io.apicurio.hub.api.filters.DisableCachingFilter.doFilter(DisableCachingFilter.java:66)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at io.apicurio.hub.api.filters.CorsFilter.doFilter(CorsFilter.java:64)
    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 org.keycloak.adapters.undertow.UndertowAuthenticatedActionsHandler.handleRequest(UndertowAuthenticatedActionsHandler.java:66)
    at org.wildfly.swarm.keycloak.deployment.SecurityContextServletExtension.lambda$null$0(SecurityContextServletExtension.java:40)
    at org.wildfly.swarm.generated.FaviconErrorHandler.handleRequest(FaviconErrorHandler.java:61)
    at io.undertow.server.handlers.PathHandler.handleRequest(PathHandler.java:94)
    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.DisableCacheHandler.handleRequest(DisableCacheHandler.java:33)
    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.security.handlers.AuthenticationConstraintHandler.handleRequest(AuthenticationConstraintHandler.java:53)
    at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
    at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
    at io.undertow.servlet.handlers.security.ServletSecurityConstraintHandler.handleRequest(ServletSecurityConstraintHandler.java:59)
    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 org.keycloak.adapters.undertow.ServletPreAuthActionsHandler.handleRequest(ServletPreAuthActionsHandler.java:69)
    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 org.wildfly.swarm.keycloak.deployment.KeycloakThreadSetupHandler.lambda$create$0(KeycloakThreadSetupHandler.java:35)
    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: io.apicurio.hub.core.storage.StorageException: Error listing API designs.
    at io.apicurio.hub.core.storage.jdbc.JdbcStorage.listApiDesigns(JdbcStorage.java:885)
    at io.apicurio.hub.core.storage.jdbc.JdbcStorage$Proxy$_$$_WeldClientProxy.listApiDesigns(Unknown Source)
    at io.apicurio.hub.api.rest.impl.DesignsResource.listDesigns(DesignsResource.java:164)
    ... 84 more
Caused by: org.jdbi.v3.core.statement.UnableToCreateStatementException: org.postgresql.util.PSQLException: This connection has been closed. [statement:"SELECT d.* FROM api_designs d JOIN acl a ON a.design_id = d.id WHERE a.user_id = ?", rewritten:"SELECT d.* FROM api_designs d JOIN acl a ON a.design_id = d.id WHERE a.user_id = ?", parsed:"ParsedSql{sql='SELECT d.* FROM api_designs d JOIN acl a ON a.design_id = d.id WHERE a.user_id = ?', parameters=ParsedParameters{positional=true, parameterNames=[?]}}", arguments:{positional:{0:tianjie}, named:{}, finder:[]}]
    at org.jdbi.v3.core.statement.SqlStatement.internalExecute(SqlStatement.java:1548)
    at org.jdbi.v3.core.result.ResultProducers.lambda$getResultSet$2(ResultProducers.java:67)
    at org.jdbi.v3.core.result.ResultIterable.lambda$of$0(ResultIterable.java:53)
    at org.jdbi.v3.core.result.ResultIterable.stream(ResultIterable.java:141)
    at org.jdbi.v3.core.result.ResultIterable.collect(ResultIterable.java:197)
    at org.jdbi.v3.core.result.ResultIterable.list(ResultIterable.java:186)
    at io.apicurio.hub.core.storage.jdbc.JdbcStorage.lambda$listApiDesigns$30(JdbcStorage.java:882)
    at org.jdbi.v3.core.Jdbi.withHandle(Jdbi.java:339)
    at io.apicurio.hub.core.storage.jdbc.JdbcStorage.listApiDesigns(JdbcStorage.java:876)
    ... 86 more
Caused by: org.postgresql.util.PSQLException: This connection has been closed.
    at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:803)
    at org.postgresql.jdbc.PgConnection.prepareStatement(PgConnection.java:1621)
    at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.doPrepareStatement(BaseWrapperManagedConnection.java:758)
    at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.prepareStatement(BaseWrapperManagedConnection.java:744)
    at org.jboss.jca.adapters.jdbc.WrappedConnection.prepareStatement(WrappedConnection.java:493)
    at org.jdbi.v3.core.statement.DefaultStatementBuilder.create(DefaultStatementBuilder.java:57)
    at org.jdbi.v3.core.statement.SqlStatement.internalExecute(SqlStatement.java:1540)
    ... 94 more

question

Source

askfor

All 7 comments

Unfortunately I have not seen this issue before. Based on a little bit of googling, my best guess is that some other database error is happening (e.g. a transient connection issue between the app and the database) and is not being properly reported in the log (but is perhaps reported to the UI?). If that happens, then the connection might get closed but also returned to the connection pool, resulting in the 'connection has been closed' error later.

Have you seen any other errors, perhaps in the UI only?

How reproducible is this? Can you make it happen with some repeatable steps, or does it seem random?

EricWittmann on 23 Apr 2019

No, I didn't notice other errors before this exception.
I read some post somewhere, it says that mysql has a default wait_timeout, and it will close inactive connections after this, so background-validation has to be set. I didn't find the dockerfile for apicurio api, I don't know if this was already set in the docker image. And I didn't know if there's a similar parameter for postgresql, since this also happens when we use pg.
Maybe set background-validation would be better?

https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_wait_timeout
https://docs.jboss.org/jbossas/docs/Server_Configuration_Guide/beta500/html/ch13s13.html

askfor on 23 Apr 2019

Interesting. Does the timing of the error work out for this theory? How long does Apicurio run before this issue pops up?

Here is the docker image for apicurio-api: https://github.com/Apicurio/apicurio-studio/tree/master/platforms/thorntail/api

EricWittmann on 23 Apr 2019

The time didn't match, it's about 30min in the recent case.
Now I'm trying to add these validation parameters to the startup command line as documented here.
https://github.com/thorntail/thorntail/tree/master/fractions/javaee/datasources#mysql
Will post the test result here.

askfor on 25 Apr 2019

👍1

OK much appreciated. If these settings take care of the issue then I'll obviously make sure we get them added as defaults.

EricWittmann on 25 Apr 2019

After a few days test run, It seems to be working.
So add these following parameters to dockerfile would be useful.

    -Dthorntail.datasources.data-sources.ApicurioDS.valid-connection-checker-class-name={APICURIO_DB_VALID_CONNECTION_CHECKER_CLASS_NAME}\
    -Dthorntail.datasources.data-sources.ApicurioDS.validate-on-match={APICURIO_DB_VALID_ON_MATCH}\
    -Dthorntail.datasources.data-sources.ApicurioDS.background-validation={APICURIO_DB_BACKGROUND_VALIDATION}\
    -Dthorntail.datasources.data-sources.ApicurioDS.exception-sorter-class-name={APICURIO_DB_EXCEPTION_SORTER_CLASS_NAME}\

askfor on 28 Apr 2019

👍1

Thanks for figuring this out, @askfor - very much appreciate the followup. I'll update the docker images and then document these settings in the apicurio documentation.

EricWittmann on 29 Apr 2019

Was this page helpful?

0 / 5 - 0 ratings