2.1.3 server/2.1.3 code: ODatabaseException: Database memory:X is closed during Integration tests

[zifnab87]

I have integration tests and I have an in memory database that before each test class I import. All the the time I get halfway through my tests (not always the same spot) and I get this message:

com.orientechnologies.orient.core.exception.ODatabaseException: Database 'memory:test' is closed
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.checkOpeness(ODatabaseDocumentTx.java:2822)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.getMetadata(ODatabaseDocumentTx.java:760)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.getMetadata(ODatabaseDocumentTx.java:120)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.searchInIndex(OCommandExecutorSQLSelect.java:2170)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.assignTarget(OCommandExecutorSQLSelect.java:481)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.executeSearch(OCommandExecutorSQLSelect.java:461)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.execute(OCommandExecutorSQLSelect.java:432)
    at com.orientechnologies.orient.core.sql.OCommandExecutorSQLDelegate.execute(OCommandExecutorSQLDelegate.java:90)
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.executeCommand(OAbstractPaginatedStorage.java:1469)
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.command(OAbstractPaginatedStorage.java:1450)
    at com.orientechnologies.orient.core.command.OCommandRequestTextAbstract.execute(OCommandRequestTextAbstract.java:63)
    at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.command(ONetworkProtocolBinary.java:1319)
    at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.executeRequest(ONetworkProtocolBinary.java:396)
    at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:223)
    at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:77)

com.orientechnologies.orient.core.exception.ODatabaseException: Database 'memory:test' is closed
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.checkOpeness(ODatabaseDocumentTx.java:2822)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.begin(ODatabaseDocumentTx.java:1642)
    at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.commit(ONetworkProtocolBinary.java:1218)
    at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.executeRequest(ONetworkProtocolBinary.java:400)
    at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:223)
    at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:77)

even though before returning same OrientGraph object I check if it isClosed() and I do .begin()..without any result.. The exception halts my integration tests and they never finish.. This started happening when I was reusing the same object for all the tests in a class instead of doing new OrientGraph(connString) every time.

In each of my 10+ classes I setup @BeforeClass an in-memory database using this code (:

public class InMemoryDatabaseSetup {

    public static String DB = "test";

    public static void main(String args[]){
        setup();
    }

    public static void setup() {
        OServerAdmin serverAdmin;
        try {
            serverAdmin = new OServerAdmin("remote:localhost/"+DB).connect("root", "admin");
            if (!serverAdmin.existsDatabase()) {
                serverAdmin.createDatabase(DB, "graph", "memory");
                System.out.println("Database "+DB+" doesn't exist - it was created");
            }
            else {
                serverAdmin.dropDatabase(null);
                serverAdmin.createDatabase(DB, "graph", "memory");
                System.out.println("Database "+DB+" exists - it was dropped and created");
            }
            serverAdmin.close();

            ODatabaseDocumentTx db = new ODatabaseDocumentTx("remote:localhost/"+DB);
            db.open("root", "admin");
            try{
              OCommandOutputListener listener = new OCommandOutputListener() {
                @Override
                public void onMessage(String iText) {
                  System.out.print(iText);
                }
              };

              ODatabaseImport dbImport = new ODatabaseImport(db, "D:/temp/db-dump-0.76-with-2.2-alpha.gz", listener);
              dbImport.importDatabase();
              dbImport.close();
            } 

            finally {
              db.close();
            }

        } catch (Exception e) {
            e.printStackTrace();

        }
    }

This is similar to those closed issues #3260, #3678

I even tried OrientGraphFactory factory with a pool size of 10 and get the OrientGraph objects with factory.getTx().. Also made sure to do @after graph.shutdown().. Still the tests are stuck :/
Any help with this?
Thanks

[zifnab87]

@lvca please let me know if there is a quick workaround. I had to halt development because now that I have injected the database to all of my classes instead of making a new connection everytime .. my integration tests can't complete.. Thanks

[andrii0lomakin]

Hi,
Why do you use 2.2-alpha and not 2.1 version at least ?
This branch (2.2-alpha) was not updated for a months.

[zifnab87]

Hi @Laa, as you can see I even migrated to 2.1.2 server and code and I still have the same issue.. I am trying to replicate it with a small code subset because the integration tests I have are quite a lot. Please let me know if I could provide (and how) more information apart from the the stacktrace. Thanks

[zifnab87]

I am also getting those warnings

Oct 01, 2015 7:52:59 PM com.orientechnologies.common.log.OLogManager log
WARNING: Caught I/O errors from Not connected (local socket=?), trying to reconnect (error: java.io.EOFException)
Oct 01, 2015 7:52:59 PM com.orientechnologies.common.log.OLogManager log
WARNING: Connection re-acquired transparently after 5ms and 1 retries to server '127.0.0.1:2424/test': no errors will be thrown at application level

almost everytime I import and connect to in memory test database

---

I also get this related error:

20:54:07.108 [main] DEBUG o.s.t.c.s.DirtiesContextTestExecutionListener - After test method: context [DefaultTestContext@405c25a4 testClass = FactSerializationTest, testInstance = com.xxxxx.test.integration.serializations.FactSerializationTest@417ad40d, testMethod = should_work@FactSerializationTest, testException = org.junit.internal.runners.model.MultipleFailureException: There were 2 errors:
  com.orientechnologies.orient.core.exception.ODatabaseException(Database 'memory:test' is closed)
  com.orientechnologies.orient.core.exception.ODatabaseException(Database 'memory:test' is closed), mergedContextConfiguration = [MergedContextConfiguration@70cd0be5 testClass = FactSerializationTest, locations = '{}', classes = '{class com.xxxx.config.TestConfig}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]]], class dirties context [false], class mode [null], method dirties context [false].
20:54:07.109 [main] DEBUG o.s.t.c.s.DirtiesContextTestExecutionListener - After test class: context [DefaultTestContext@405c25a4 testClass = FactSerializationTest, testInstance = [null], testMethod = [null], testException = [null], mergedContextConfiguration = [MergedContextConfiguration@70cd0be5 testClass = FactSerializationTest, locations = '{}', classes = '{class com.xxxx.config.TestConfig}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]]], dirtiesContext [false].```

[zifnab87]

If I use the trick from #3678 (#3678 (comment)) using my own subclass of OrientGraph injecting the logic just before super.addVertex() or super.addEdge is called things are a bit more stable

But I still get once in a while stuck tests with that in server console

2015-10-04 21:34:47:110 SEVER Authentication error of remote client /127.0.0.1:54122: shutdown is aborted. [ONetworkProtocolBinary]

Or I am getting this warning from time to time:

WARNING: Error deserializing record with id #25:183 send this data for debugging: ABJJbm5lclRleHRBAAAAIDsAAAA6MQAAAF8zAAAAZQAyQCBhIEAgYiBAIGMgQCBkIEAgZSBAIGYgQEhlODgxNDgxNy01ZDA0LTRhN2UtODhiNC03ZDQ1OTQ1ZmQ2YzOQpa/MhlRIYTFlMGM5ZjgtNjM1Ni00OTJkLThmOWUtYmZiNjkyODMxN2E2 
com.orientechnologies.orient.core.exception.ODatabaseException: Database instance is not set in current thread. Assure to set it with: ODatabaseRecordThreadLocal.INSTANCE.set(db);
    at com.orientechnologies.orient.core.db.ODatabaseRecordThreadLocal.get(ODatabaseRecordThreadLocal.java:51)
    at com.orientechnologies.orient.core.record.ORecordAbstract.getDatabase(ORecordAbstract.java:240)
    at com.orientechnologies.orient.core.record.impl.ODocument.getGlobalPropertyById(ODocument.java:2147)
    at com.orientechnologies.orient.core.record.impl.ODocumentInternal.getGlobalPropertyById(ODocumentInternal.java:60)
    at com.orientechnologies.orient.core.serialization.serializer.record.binary.ORecordSerializerBinaryV0.getGlobalProperty(ORecordSerializerBinaryV0.java:279)
    at com.orientechnologies.orient.core.serialization.serializer.record.binary.ORecordSerializerBinaryV0.deserializePartial(ORecordSerializerBinaryV0.java:129)
    at com.orientechnologies.orient.core.serialization.serializer.record.binary.ORecordSerializerBinary.fromStream(ORecordSerializerBinary.java:72)
    at com.orientechnologies.orient.core.record.impl.ODocument.deserializeFields(ODocument.java:1817)
    at com.orientechnologies.orient.core.record.impl.ODocument.checkForFields(ODocument.java:2405)
    at com.orientechnologies.orient.core.record.impl.ODocument.rawField(ODocument.java:767)
    at com.orientechnologies.orient.core.record.impl.ODocument.field(ODocument.java:792)
    at com.tinkerpop.blueprints.impls.orient.OrientElement.getProperty(OrientElement.java:273)
    at com.xxxxx.util.ObjectMapper.mapVertexToObj(ObjectMapper.java:81)
    at com.xxxx.test.integration.services.InnerTextCreateTest.should_store_it(InnerTextCreateTest.java:45)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Unknown Source)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
    at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:73)
    at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
    at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:82)
    at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:73)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
    at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:224)
    at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:83)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
    at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
    at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61)
    at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:68)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
    at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:163)
    at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)
    at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:459)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:675)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:382)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:192)

[zifnab87]

To my surprise

I was doing

if(graph.isClosed()) {
graph.begin();
}

and begin() was one of the reasons throwing exceptions "database X is closed". I think begin() is not clear why is needed.. and how it is possible to reuse a connection object that is shared among multiple objects that will need to be on the same transaction..

Weird things were happening since I was comiting against the different connection while both against the same connection string.. But connection pool should be smart . I feel connection management makes my life more difficult than it should be..

[lvca]

begin() begins a transaction. A closed graph can't be used anymore (there is not open in Blueprints API, sorry)

[zifnab87]

@Laa @lvca Please don't close those so quickly. I've been fighting this for weeks, refactoring hundreds of places multiple times and it is getting annoying. This problem has to do with OrientDB.. I was able to replicate the problem in this small piece of code (the same happens with shutdown()'s ):

import com.orientechnologies.orient.client.remote.OServerAdmin;
import com.orientechnologies.orient.core.command.OCommandOutputListener;
import com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx;
import com.orientechnologies.orient.core.db.tool.ODatabaseImport;
import com.tinkerpop.blueprints.impls.orient.OrientGraph;
import com.tinkerpop.blueprints.impls.orient.OrientGraphFactory;

public class TestBed {
    private static OrientGraphFactory factory = new OrientGraphFactory(ConnectionStrings.testConnection).setupPool(1,10);
    public static void main(String args[]){

        for(int i=0; i<1000; i++){
            setup();
            System.out.println("\n--------------------Trial:"+i+"-----------------");
            OrientGraph graph = factory.getTx();
            graph.addVertex("class:someClass");
            graph.commit();
        }

    }

    public static void setup() {
        String DB="test";
        OServerAdmin serverAdmin;
        try {
            serverAdmin = new OServerAdmin("remote:localhost/"+DB).connect("root", "admin");
            if (!serverAdmin.existsDatabase()) {
                serverAdmin.createDatabase(DB, "graph", "memory");
                System.out.println("Database "+DB+" doesn't exist - it was created");
            }
            else {
                serverAdmin.dropDatabase(null);
                serverAdmin.createDatabase(DB, "graph", "memory");
                System.out.println("Database "+DB+" exists - it was dropped and created");
            }
            serverAdmin.close();

            ODatabaseDocumentTx db = new ODatabaseDocumentTx("remote:localhost/"+DB);
            db.open("root", "admin");
            try{
              OCommandOutputListener listener = new OCommandOutputListener() {
                @Override
                public void onMessage(String iText) {
                  System.out.print(iText);
                }
              };

              ODatabaseImport dbImport = new ODatabaseImport(db, "D:/temp/xxxx-orientdb-dump-0.76-no-indices.gz", listener);
              dbImport.importDatabase();
              dbImport.close();
            } 

            finally {
              db.close();
            }

        } catch (Exception e) {
            e.printStackTrace();

        }
    }
}

Here is the issue and it happens in random numbef of trials usually before 10th.. I even tried different size of pools and it is replicated every single time.. In this example as I do with my Integration tests I load an in memory database in each loop..

The first trial I get this warning

Oct 05, 2015 11:05:10 PM com.orientechnologies.common.log.OLogManager log
WARNING: Requested command 'Committing the active transaction to create the new type 'someClass' as subclass of 'V'. The transaction will be reopen right after that. To avoid this behavior create the classes outside the transaction' must be executed outside active transaction: the transaction will be committed and reopen right after it. To avoid this behavior execute it outside a transaction

and then every other trial before the last I get

--------------------Trial:6-----------------
Oct 05, 2015 11:05:36 PM com.orientechnologies.common.log.OLogManager log
WARNING: Caught I/O errors from /127.0.0.1:2424 (local socket=/127.0.0.1:54672), trying to reconnect (error: java.io.EOFException)
Oct 05, 2015 11:05:36 PM com.orientechnologies.common.log.OLogManager log
SEVERE: Removing disconnected network channel '127.0.0.1:2424/test'...
Oct 05, 2015 11:05:36 PM com.orientechnologies.common.log.OLogManager log
WARNING: Connection re-acquired transparently after 8ms and 1 retries to server '127.0.0.1:2424/test': no errors will be thrown at application level

This is the exception that randomly kills my integration tests

Database import completed in 4009 ms
--------------------Trial:7-----------------
Exception in thread "main" com.orientechnologies.orient.core.exception.ODatabaseException: Database 'memory:test' is closed
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.checkOpeness(ODatabaseDocumentTx.java:2826)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.begin(ODatabaseDocumentTx.java:1646)
    at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.commit(ONetworkProtocolBinary.java:1218)
    at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.executeRequest(ONetworkProtocolBinary.java:400)
    at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:223)
    at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:77)

If I remove import and only create empty databases I get:

Oct 05, 2015 11:21:53 PM com.orientechnologies.common.log.OLogManager log
INFO: OrientDB auto-config DISKCACHE=7,419MB (heap=2,706MB os=12,173MB disk=37,648MB)
Database test exists - it was dropped and created

--------------------Trial:0-----------------
Oct 05, 2015 11:21:56 PM com.orientechnologies.common.log.OLogManager log
WARNING: Requested command 'Committing the active transaction to create the new type 'someClass' as subclass of 'V'. The transaction will be reopen right after that. To avoid this behavior create the classes outside the transaction' must be executed outside active transaction: the transaction will be committed and reopen right after it. To avoid this behavior execute it outside a transaction
Database test exists - it was dropped and created

--------------------Trial:1-----------------

Oct 05, 2015 11:21:56 PM com.orientechnologies.common.log.OLogManager log
SEVERE: Exception during commit of active transaction
com.orientechnologies.orient.core.exception.ODatabaseException: Database 'memory:test' is closed
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.checkOpeness(ODatabaseDocumentTx.java:2826)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.begin(ODatabaseDocumentTx.java:1646)
    at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.commit(ONetworkProtocolBinary.java:1218)
    at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.executeRequest(ONetworkProtocolBinary.java:400)
    at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:223)
    at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:77)

At the same time in server.bat console I get

2015-10-05 23:30:53:465 INFO  Received shutdown command from the remote client /127.0.0.1:58328 [ONetworkProtocolBinary]
2015-10-05 23:30:53:475 SEVER Authentication error of remote client /127.0.0.1:58328: shutdown is aborted. [ONetworkProtocolBinary]

Please have a look into that, it really holds me down.

Thanks,
Michail