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)