Closed PierreMardon closed 5 years ago
I removed most of the classes of my project so that you can easily reproduce and inspect the relevant code only.
EDIT: the leak is caused by the use of OpenEntityManagerInViewFilter
that fails to release the connection when StreamingResponseBody
is used. Commenting it in AppConfig.java
solves the leak. Still, I need this filter :P
To be able to start the app, you have to create an empty schema test_schema
in a local MySQL database (configure your connection in application.yml
).
http://localhost:8086/ws3/file/data/?file=ANY_STRING
.GeneralFilter
class is the only one using JPA and calling the MyUserRepository
, it's the only place where HikaryCP is asked for a connection.2019-01-27 18:54:01.350 DEBUG 18739 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Before cleanup stats (total=6, active=1, idle=5, waiting=0)
2019-01-27 18:54:01.351 DEBUG 18739 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - After cleanup stats (total=6, active=1, idle=5, waiting=0)
And later the leak detection:
java.lang.Exception: Apparent connection leak detected
at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128) ~[HikariCP-2.7.9.jar:na]
at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:35) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:106) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:136) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:47) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:145) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:171) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:147) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1985) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1915) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1893) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.loader.Loader.doQuery(Loader.java:938) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:341) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.loader.Loader.doList(Loader.java:2692) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.loader.Loader.doList(Loader.java:2675) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2507) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.loader.Loader.list(Loader.java:2502) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:502) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:392) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:216) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1490) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1445) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1414) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.query.internal.AbstractProducedQuery.getSingleResult(AbstractProducedQuery.java:1463) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.hibernate.query.criteria.internal.compile.CriteriaQueryTypeQueryAdapter.getSingleResult(CriteriaQueryTypeQueryAdapter.java:107) ~[hibernate-core-5.2.17.Final.jar:5.2.17.Final]
at org.springframework.data.jpa.repository.query.JpaQueryExecution$SingleEntityExecution.doExecute(JpaQueryExecution.java:214) ~[spring-data-jpa-2.0.8.RELEASE.jar:2.0.8.RELEASE]
at org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:91) ~[spring-data-jpa-2.0.8.RELEASE.jar:2.0.8.RELEASE]
at org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:136) ~[spring-data-jpa-2.0.8.RELEASE.jar:2.0.8.RELEASE]
at org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:125) ~[spring-data-jpa-2.0.8.RELEASE.jar:2.0.8.RELEASE]
at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.doInvoke(RepositoryFactorySupport.java:590) ~[spring-data-commons-2.0.8.RELEASE.jar:2.0.8.RELEASE]
at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:578) ~[spring-data-commons-2.0.8.RELEASE.jar:2.0.8.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.7.RELEASE.jar:5.0.7.RELEASE]
at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:59) ~[spring-data-commons-2.0.8.RELEASE.jar:2.0.8.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.7.RELEASE.jar:5.0.7.RELEASE]
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:294) ~[spring-tx-5.0.7.RELEASE.jar:5.0.7.RELEASE]
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98) ~[spring-tx-5.0.7.RELEASE.jar:5.0.7.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.7.RELEASE.jar:5.0.7.RELEASE]
at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:139) ~[spring-tx-5.0.7.RELEASE.jar:5.0.7.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.7.RELEASE.jar:5.0.7.RELEASE]
at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:135) ~[spring-data-jpa-2.0.8.RELEASE.jar:2.0.8.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.7.RELEASE.jar:5.0.7.RELEASE]
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) ~[spring-aop-5.0.7.RELEASE.jar:5.0.7.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.7.RELEASE.jar:5.0.7.RELEASE]
at org.springframework.data.repository.core.support.SurroundingTransactionDetectorMethodInterceptor.invoke(SurroundingTransactionDetectorMethodInterceptor.java:61) ~[spring-data-commons-2.0.8.RELEASE.jar:2.0.8.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.7.RELEASE.jar:5.0.7.RELEASE]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) ~[spring-aop-5.0.7.RELEASE.jar:5.0.7.RELEASE]
at com.sun.proxy.$Proxy96.findFirstByUuid(Unknown Source) ~[na:na]
at com.myproject.filter.GeneralFilter.addRequestInfo(GeneralFilter.java:39) ~[classes/:na]
...
You can experiment that changing the ResponseEntity
body type to String
and returning an empty string fixes the leak.
I'm sorry for this bug report, in fact adding @Async
annotation on my service function solves the issue, so it's not a bug, my bad !
Ok so indeed it would solve the leak but also any real IO transfert would fail (try to stream any resource in the body to see it). So bad solution, still a bug, sorry for the premature closure!
Thanks for the sample but there's still quite a lot to it. If you have time to strip it down further, including replacing the need for MySQL with an in-memory database (H2 or HSQLDB), it will increase the changes of someone having the time to investigate.
I'm sorry to be that guy, but I prefer to tell you directly that I won't be able to take time to enhance the sample.
The problem is caused by a mis-configuration of the OpenEntityManagerInViewFilter
. Its dispatcher types have not been customised so it is only called on request dispatch and is not called on async dispatch. As a result, the session that it opens is never closed which causes the database connection to leak.
So was this fixed? Still running in CP leakage when using StreamingRequestBody
with JPA. Not sure, since the status invalid
was applied on this issue.
@alexpartsch As far as we could determine, there was nothing to fix in Spring Boot as the problem was caused by misconfiguration in the application. Please see my comment immediately above yours for details.
@wilkinsona I read your comment, but was under assumption that the part of Spring Boot handling the StreamingRequestBody
threading has to "customise the dispatcher types" (due to my lack of understanding of OpenEntityManagerInViewFilter
I'm not aware of what these dispatcher types are and where one can customise them, but trying to find out now.), but as I understand from your last comment, the framework user is probably in charge of that.
The dispatcher types are part of the servlet spec and they govern the types of dispatch for which a filter is invoked. When you're using a StreamingResponseBody
an async dispatch is performed so you need to be sure that the filter's been registered for async dispatches otherwise it won't get a chance to clean up properly once the response has been sent. You can configure the dispatcher types using a FilterRegistrationBean
. Note that if you are using Spring Boot 2.3, the OpenEntityManagerInViewFilter
, which is a OncePerRequestFilter
, will be registered for async dispatches by default due to the changes made in https://github.com/spring-projects/spring-boot/issues/18953.
Thanks for the infos! I understand more know.
I'm running Spring Boot 2.3.3, but it seems no OpenEntityManagerInViewFilter
is registered or at least executed on any request. I tried to define it myself but fail with a LazyInitialisationException
due to no session being open in the async requests. Here is my filter bean definition:
@Bean
@Primary
public FilterRegistrationBean<OpenEntityManagerInViewFilter> openEntityManagerInViewFilterFilterRegistrationBean() {
var filter = new OpenEntityManagerInViewFilter();
var registrationBean = new FilterRegistrationBean<>(filter);
registrationBean.setAsyncSupported(true);
registrationBean.addUrlPatterns("/*");
registrationBean.setDispatcherTypes(DispatcherType.REQUEST, DispatcherType.ASYNC);
return registrationBean;
}
I use the default EntityManagerFactory
configuration with hibernate so I don't think I need to configure more π€ ... but it still seems to not be executed. Since you say 2.3 already defines it as ASNY my leak can be caused by something else then π
my leak can be caused by something else then π
It certainly sounds like it. If you can provide us with a minimal sample project that reproduces the leak, please open a new issue and we can take a look.
Okay, so after defining my Bean as described above another error due to my transaction management was rissen. Fixing that, the new OpenEntityManagerInViewFilter
seems to work fine now. Are you sure that DispatcherType.ASYNC
is enabled by default in Spring Boot 2.3.3?
As sure as I can be. There's a test that verifies that's the case:
Okay, found the issue, just for further reference: When testing with MockMvc
and StreamingRequestBody
one should use the asyncDispatch
RequestBuilder
for retrieving and properly handling the response (see here). I removed my OpenEntityManagerInViewFilter
filter registration and it still worked πββοΈ
Thanks @wilkinsona for the help!
Hi,
I faced a HikariCP leak that I thought was caused by my code but it appears that the use of
StreamingResponseBody
causes it by itself.After removing all unneeded code, I come to a pretty straight forward reproduction case.
With
StreamingResponseBody
, one connection stays active forever in the CP. This connection is opened in one of my filterOncePerRequestFilter
to fill a request-scoped component.[UPDATE] see the next comment for a reproduction scenario (project zip included).
In a controller I directly call this service function:
When I just replace the type of response body to String, everything is ok:
Here is my pom:
Some config:
My yml props: