You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@ofbiz.apache.org by "Sixty One (Jira)" <ji...@apache.org> on 2022/05/11 13:34:00 UTC
[jira] [Created] (OFBIZ-12613) StackOverflowError and database blocking when exporting "performFind" via rest-api
Sixty One created OFBIZ-12613:
---------------------------------
Summary: StackOverflowError and database blocking when exporting "performFind" via rest-api
Key: OFBIZ-12613
URL: https://issues.apache.org/jira/browse/OFBIZ-12613
Project: OFBiz
Issue Type: Improvement
Reporter: Sixty One
Attachments: image-2022-05-11-15-18-56-803.png, image-2022-05-11-15-23-54-422.png, image-2022-05-11-15-29-11-425.png, rest-expose-performFind-no-iterator.patch, rest-expose-performFind.patch
I am running on latest trunk but cannot select trunk within "Affects Version/s" here.
I experimented with OFBiz findServices (performFind, performFindList, performFindItem) via rest-api. I observed two things that I'd like to understand as I do not know if those are really bugs and such things are of interest for the OFBiz community in general.
h1. performFind leads to StackOverflowError
I exposed the performFindService within "rest-expose-performFind.patch". Requesting a search via rest-api:
{code:java}
POST /rest/services/performFind HTTP/1.1
Host: localhost:8443
Authorization: Bearer ...
Content-Type: application/json
{
"entityName": "Facility",
"inputFields": {
"facilityName": "a",
"facilityName_ic": "Y",
"facilityName_op": "contains"
}
} {code}
Leads to an infinite loop that "finishes" with an StackOverFlowError:
!image-2022-05-11-15-18-56-803.png!
I reckon that this is due to the fact that the performFind-service retunrs an Iterator instead of a List.
h1. performFind without ListIterator leaves database connections open
What I tried next is to get rid of that ListIterator within rest-expose-performFind-no-iterator.patch
!image-2022-05-11-15-23-54-422.png!
It "works" (at least I can work with the response) but somehow the performFind-service leaves the database connections open until they finally block after ~250 requests. Afterwards there's no chance to send new requests or login to OFBiz without a restart.
{code:java}
2022-05-11 15:24:47,140 |jsse-nio-8443-exec-7 |ServiceDispatcher |T| Sync service [rest-api/prepareFind] finished in [1] milliseconds
2022-05-11 15:24:47,141 |jsse-nio-8443-exec-7 |ServiceDispatcher |T| Sync service [rest-api/executeFind] finished in [1] milliseconds
2022-05-11 15:24:47,141 |jsse-nio-8443-exec-7 |ServiceDispatcher |T| Sync service [rest-api/performFind] finished in [2] milliseconds
2022-05-11 15:24:48,038 |jsse-nio-8443-exec-1 |ServiceRequestFilter |I| Service request is going to get validated!
2022-05-11 15:24:48,040 |jsse-nio-8443-exec-1 |ServiceDispatcher |T| Sync service [rest-api/executeFind] finished in [1] milliseconds
2022-05-11 15:24:48,040 |jsse-nio-8443-exec-1 |ServiceDispatcher |T| Sync service [rest-api/performFind] finished in [1] milliseconds
2022-05-11 15:26:48,826 |sse-nio-8443-exec-10 |GenericDelegator |E| Failure in findByCondition operation for entity [UserLogin]: org.apache.ofbiz.entity.GenericDataSourceException: Unable to establish a connection with the database. (Unable to acquire a new connection from the pool). Rolling back transaction.
org.apache.ofbiz.entity.GenericDataSourceException: Unable to establish a connection with the database. (Unable to acquire a new connection from the pool)
at org.apache.ofbiz.entity.jdbc.SQLProcessor.getConnection(SQLProcessor.java:287) ~[main/:?]
at org.apache.ofbiz.entity.jdbc.SQLProcessor.prepareStatement(SQLProcessor.java:372) ~[main/:?]
at org.apache.ofbiz.entity.datasource.GenericDAO.selectListIteratorByCondition(GenericDAO.java:806) ~[main/:?]
at org.apache.ofbiz.entity.datasource.GenericHelperDAO.findListIteratorByCondition(GenericHelperDAO.java:157) ~[main/:?]
at org.apache.ofbiz.entity.GenericDelegator.find(GenericDelegator.java:1600) ~[main/:?]
at org.apache.ofbiz.entity.GenericDelegator.findList(GenericDelegator.java:1648) ~[main/:?]
at org.apache.ofbiz.entity.util.EntityQuery.query(EntityQuery.java:468) ~[main/:?]
at org.apache.ofbiz.entity.util.EntityQuery.queryList(EntityQuery.java:397) ~[main/:?]
at org.apache.ofbiz.entity.util.EntityQuery.queryOne(EntityQuery.java:441) ~[main/:?]
at org.apache.ofbiz.ws.rs.security.auth.APIAuthFilter.extractUserLoginFromJwtClaim(APIAuthFilter.java:143) ~[main/:?]
at org.apache.ofbiz.ws.rs.security.auth.APIAuthFilter.filter(APIAuthFilter.java:105) ~[main/:?]
at org.glassfish.jersey.server.ContainerFilteringStage.apply(ContainerFilteringStage.java:108) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.ContainerFilteringStage.apply(ContainerFilteringStage.java:44) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.process.internal.Stages.process(Stages.java:173) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:245) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:292) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:274) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:244) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265) ~[jersey-common-2.31.jar:?]
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:232) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:680) ~[jersey-server-2.31.jar:?]
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:394) ~[jersey-container-servlet-core-2.31.jar:?]
at org.glassfish.jersey.servlet.ServletContainer.serviceImpl(ServletContainer.java:386) ~[jersey-container-servlet-core-2.31.jar:?]
at org.glassfish.jersey.servlet.ServletContainer.doFilter(ServletContainer.java:561) ~[jersey-container-servlet-core-2.31.jar:?]
at org.glassfish.jersey.servlet.ServletContainer.doFilter(ServletContainer.java:502) ~[jersey-container-servlet-core-2.31.jar:?]
at org.glassfish.jersey.servlet.ServletContainer.doFilter(ServletContainer.java:439) ~[jersey-container-servlet-core-2.31.jar:?]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) ~[tomcat-catalina-9.0.60.jar:9.0.60]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) ~[tomcat-catalina-9.0.60.jar:9.0.60]
at org.apache.logging.log4j.web.Log4jServletFilter.doFilter(Log4jServletFilter.java:71) ~[log4j-web-2.17.2.jar:2.17.2]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) ~[tomcat-catalina-9.0.60.jar:9.0.60]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) ~[tomcat-catalina-9.0.60.jar:9.0.60]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197) ~[tomcat-catalina-9.0.60.jar:9.0.60]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) ~[tomcat-catalina-9.0.60.jar:9.0.60]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541) ~[tomcat-catalina-9.0.60.jar:9.0.60]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135) ~[tomcat-catalina-9.0.60.jar:9.0.60]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-catalina-9.0.60.jar:9.0.60]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) ~[tomcat-catalina-9.0.60.jar:9.0.60]
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687) ~[tomcat-catalina-9.0.60.jar:9.0.60]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360) ~[tomcat-catalina-9.0.60.jar:9.0.60]
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399) ~[tomcat-coyote-9.0.60.jar:9.0.60]
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-coyote-9.0.60.jar:9.0.60]
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:889) ~[tomcat-coyote-9.0.60.jar:9.0.60]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1743) ~[tomcat-coyote-9.0.60.jar:9.0.60]
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-coyote-9.0.60.jar:9.0.60]
at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) ~[tomcat-util-9.0.60.jar:9.0.60]
at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) ~[tomcat-util-9.0.60.jar:9.0.60]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-util-9.0.60.jar:9.0.60]
at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_322]
Caused by: java.sql.SQLException: Unable to acquire a new connection from the pool
at org.apache.commons.dbcp2.managed.ManagedConnection.updateTransactionStatus(ManagedConnection.java:305) ~[commons-dbcp2-2.9.0.jar:2.9.0]
at org.apache.commons.dbcp2.managed.ManagedConnection.<init>(ManagedConnection.java:89) ~[commons-dbcp2-2.9.0.jar:2.9.0]
at org.apache.commons.dbcp2.managed.ManagedDataSource.getConnection(ManagedDataSource.java:64) ~[commons-dbcp2-2.9.0.jar:2.9.0]
at org.apache.ofbiz.entity.connection.DebugManagedDataSource.getConnection(DebugManagedDataSource.java:57) ~[main/:?]
at org.apache.ofbiz.entity.connection.DBCPConnectionFactory.getConnection(DBCPConnectionFactory.java:68) ~[main/:?]
at org.apache.ofbiz.entity.transaction.GeronimoTransactionFactory.getConnection(GeronimoTransactionFactory.java:77) ~[main/:?]
at org.apache.ofbiz.entity.jdbc.SQLProcessor.getConnection(SQLProcessor.java:282) ~[main/:?]
... 49 more
Caused by: java.util.NoSuchElementException: Timeout waiting for idle object
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:321) ~[commons-pool2-2.10.0.jar:2.10.0]
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:428) ~[commons-pool2-2.10.0.jar:2.10.0]
at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:232) ~[commons-pool2-2.10.0.jar:2.10.0]
at org.apache.commons.dbcp2.managed.ManagedConnection.updateTransactionStatus(ManagedConnection.java:302) ~[commons-dbcp2-2.9.0.jar:2.9.0]
at org.apache.commons.dbcp2.managed.ManagedConnection.<init>(ManagedConnection.java:89) ~[commons-dbcp2-2.9.0.jar:2.9.0]
at org.apache.commons.dbcp2.managed.ManagedDataSource.getConnection(ManagedDataSource.java:64) ~[commons-dbcp2-2.9.0.jar:2.9.0]
at org.apache.ofbiz.entity.connection.DebugManagedDataSource.getConnection(DebugManagedDataSource.java:57) ~[main/:?]
at org.apache.ofbiz.entity.connection.DBCPConnectionFactory.getConnection(DBCPConnectionFactory.java:68) ~[main/:?]
at org.apache.ofbiz.entity.transaction.GeronimoTransactionFactory.getConnection(GeronimoTransactionFactory.java:77) ~[main/:?]
at org.apache.ofbiz.entity.jdbc.SQLProcessor.getConnection(SQLProcessor.java:282) ~[main/:?]
... 49 more {code}
!image-2022-05-11-15-29-11-425.png!
The services performFindList and performFindItem which in fact also use performFind do not show that behavior after 250 requests. Somehow performFind leaves connections open where performFindList and performFindItem seem to close them!?
--
This message was sent by Atlassian Jira
(v8.20.7#820007)