Error on releasing database in pool

[remi-parain]

I'm facing a recurrent issue using OrientDB in remote mode (not embedded ). I don't understand what happens, some queries just fails : one time it works, one time it doesn't, it seems to be random.
I happens using OrientDbCrud built-in functions or custom queries.

There is only one instance of Wisdom server which access the DB. Both are on the same host.
Each webservice use the @async wisdom annotation.

I tested with orientDB version 2.1.0, 2.1.3 , 2.1.5 with the current (github) version of the wisdom-orientdb service.

Here is a stacktrace sample :

java code :

    @Override
    public List<POICategory> getPoiCategories() {
        return Lists.newArrayList(poicatCrud.findAll());
    }

stacktrace :

[ERROR]  c.o.o.o.d.OObjectDatabaseTxPooled {wisdom-system-executor-62} - Error on releasing database 'mrvoyage' in pool 
java.lang.IllegalStateException: Current database instance (com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx@673b0d80) is not active on current thread (Thread[wisdom-system-executor-62,5,iPOJO Extender]). Current active database is: com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx@69fceecf
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.checkIfActive(ODatabaseDocumentTx.java:3138) ~[na:na]
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.commit(ODatabaseDocumentTx.java:2557) ~[na:na]
    at com.orientechnologies.orient.object.db.OObjectDatabaseTx.commit(OObjectDatabaseTx.java:579) ~[com.orientechnologies.orientdb.object-2.1.3.jar:2.1.3]
    at com.orientechnologies.orient.object.db.OObjectDatabaseTxPooled.close(OObjectDatabaseTxPooled.java:110) ~[com.orientechnologies.orientdb.object-2.1.3.jar:2.1.3]
    at org.wisdom.orientdb.runtime.OrientDbTransactionManager.releaseDb(OrientDbTransactionManager.java:48) [org.wisdom.framework.wisdom.orientdb.object-0.3.1-SNAPSHOT.jar:na]
    at org.wisdom.orientdb.runtime.OrientDbCrudService.releaseDb(OrientDbCrudService.java:52) [org.wisdom.framework.wisdom.orientdb.object-0.3.1-SNAPSHOT.jar:na]
    at org.wisdom.orientdb.runtime.OrientDbCrudService.findAll(OrientDbCrudService.java:167) [org.wisdom.framework.wisdom.orientdb.object-0.3.1-SNAPSHOT.jar:na]
    at org.wisdom.orientdb.object.OrientDbCrud$$Proxy.findAll(Unknown Source) [na:na]
    at com.ubidreams.poi.service.PoiSrvImplOrient.__M_getPoiCategories(PoiSrvImplOrient.java:193) [com.ubidreams.mr.voyage.serveur-0.0.1-SNAPSHOT.jar:na]
    at com.ubidreams.poi.service.PoiSrvImplOrient.getPoiCategories(PoiSrvImplOrient.java) [com.ubidreams.mr.voyage.serveur-0.0.1-SNAPSHOT.jar:na]
    at com.ubidreams.poi.api.PoiService$$Proxy.getPoiCategories(Unknown Source) [na:na]
    at com.ubidreams.poi.controllers.POIController.__M_getPoiCategories(POIController.java:158) [com.ubidreams.mr.voyage.serveur-0.0.1-SNAPSHOT.jar:na]
    at com.ubidreams.poi.controllers.POIController.getPoiCategories(POIController.java) [com.ubidreams.mr.voyage.serveur-0.0.1-SNAPSHOT.jar:na]
    at sun.reflect.GeneratedMethodAccessor121.invoke(Unknown Source) ~[na:na]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_60]
    at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_60]
    at org.wisdom.router.RouteDelegate$EndOfChainInvoker.call(RouteDelegate.java:333) [router-0.10.0-SNAPSHOT.jar:na]
    at org.wisdom.api.interception.RequestContext.proceed(RequestContext.java:124) [wisdom-api-0.10.0-SNAPSHOT.jar:na]
    at org.wisdom.executors.AsyncInterceptor$1.__M_call(AsyncInterceptor.java:126) [wisdom-executors-0.10.0-SNAPSHOT.jar:na]
    at org.wisdom.executors.AsyncInterceptor$1.call(AsyncInterceptor.java) [wisdom-executors-0.10.0-SNAPSHOT.jar:na]
    at org.wisdom.executors.AsyncInterceptor$1.__M_call(AsyncInterceptor.java:123) [wisdom-executors-0.10.0-SNAPSHOT.jar:na]
    at org.wisdom.executors.AsyncInterceptor$1.call(AsyncInterceptor.java) [wisdom-executors-0.10.0-SNAPSHOT.jar:na]
    at org.wisdom.executors.Task$EnhancedCallable.call(Task.java:251) [wisdom-executors-0.10.0-SNAPSHOT.jar:na]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_60]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_60]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_60]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_60]

Have anyone faced the same issue ?

[barjo]

Hi, Thanks for the notice.
This is definitively a bug of wisdom-orientdb, that's probably due to some change that has been made in the Orientdb threading and pool model (about 6 month ago... sorry) . I will have to refactor, it is also related to #33
Thanks for having try with different Orientdb version, the current snapshot is based on orientdb 2.1.3 and the release 0.3.0 on 2.1.2, however both should work with at least any version of Orientdb > 2.1.0 and < 2.2.0 (according to their versioning scheme)

[remi-parain]

For anyone concerned, we found a temporary workaround by removing the @async annotation from Controllers. It seems to fix the issue.

[barjo]

In the current implementation, the db instance is attached to the thread that execute the controller. So when accessing a db instance in an Asynch block, the orientdb engine failed because the thread running the Asynch block is difference of the Thread on which the db instance has been attached.

[cescoffier]

This is kind of annoying because it blocks the threads. In the new version, this is critical (never ever blocks the event loop).

[barjo]

@cescoffier so they change this behavior since 2.1, and their previous pool implementation is now deprecated.
So, for now, each time we call the crudservice, it will acquire a new instance from the pool and attached the instance to the current thread (as required by orientdb), at the end of the call, the db instance is closed and normally released to the pool. If you are in a transaction, it does the acquire on the first call and the close and release at the end of the transaction. So you cannot create thread that call this instance, within a transaction, that does sound fair :P
So it's very important to configure well your db pool depending on your app. Now, orientdb provides a partitioned database pool with lock free capability.It is very important, because with such implementation if the connection pool is exhausted it won't wait, but throw an exception, you can even finely tune it to have a minimum connection number, a max connection number, and a max under high load number, so it will adapt up to this point.
I will move to the new pool implementation and refactor what needs to be.

[remi-parain]

@barjo : the refactor sounds great ^^
when you say : "it's very important to configure well your db pool depending on your app" , where can i find those settings ? in the orientDB config file (I found : db.pool.min and db.pool.max properties) or elsewhere?

[barjo]

@remi-parain yes it is those properties.

[barjo]

I start to move to the PartitionPool, but I encounter some problems orientechnologies/orientdb#4953 orientechnologies/orientdb#5231

Basically, when the db has been closed we cannot call the proxy properly. Since the implementation of the CrudService required to open and close the db for each call (excepted if we are in a transaction) that cause trouble.

One workaround could be to refactor the Orientdb crud service and add a method close and a method open, that will be call by the dev.

[barjo]

Orientdb made an hotfix for this issue, I am half way through the refactoring. Everything should come together next week.

[remi-parain]

It's really good news! Thank you @barjo. And thanks to orientDB community's reactivity as well

[barjo]

Despite the bug fix from orientdb there is still some issue with the new pool. Once the db has been closed, we cannot get the Id of the previously retrieved object. This can cause an issue if for exemple you call getId() after the db has been closed. In the current implementation of the OrientDBCrudService, we close the db after each call to it.

One workaround, could be not to close/release the db in each call, and add a method release to OrientdbCrudService contract. We could also have an Interceptor that automatically release the db at the end of each method (route) call.

WDYT?