Fwd: Orient DB: Two exceptions to go...

28 views
Skip to first unread message

Michael Widmann

unread,
Dec 2, 2011, 8:22:33 AM12/2/11
to Luca, orient-...@googlegroups.com


---------- Forwarded message ----------
From: Michael Hieß <michae...@exthex.com>
Date: 2011/12/2
Subject: Orient DB: Two exceptions to go...
To: Michael Widmann <michael...@gmail.com>


Hallo everyone!
After extending our tests cases we found two new errors.

1) Exception in thread "pool-2-thread-2" com.orientechnologies.orient.core.exception.ODatabaseException: Error on saving record #1:53

2) WARNUNG: Memory mapping error, try to reduce max memory to %d and retry...
java.io.IOException: Map failed
    at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:758)


Some explanation concerning the test case:
1) We use 5 databases in this test case
2) Every database has a dedicated worker thread which reads and writes to the defined database
3) Every operation that should be executed is added to a BlockingQueue.
4) Each thread looks at the queue and only executes its operations. (not perfect but ok for a test case. normally we use a disruptor, but that would be too much for this unit test)


As always, any hint would be great!

Log output can be found below...


Regards,
Michael


PS: To execute the test you have to set the "static final String url" parameter. Path of the orient databases.



RemoteTestNG starting
Destroying database0
database0.clean up
database0.delete db: local:D:/work/bay/testing/databases/orient_test_bulk0
database0.created: local:D:/work/bay/testing/databases/orient_test_bulk0
Destroying database1
database1.clean up
database1.delete db: local:D:/work/bay/testing/databases/orient_test_bulk1
database1.created: local:D:/work/bay/testing/databases/orient_test_bulk1
Destroying database2
database2.clean up
database2.delete db: local:D:/work/bay/testing/databases/orient_test_bulk2
database2.created: local:D:/work/bay/testing/databases/orient_test_bulk2
Destroying database3
database3.clean up
database3.delete db: local:D:/work/bay/testing/databases/orient_test_bulk3
database3.created: local:D:/work/bay/testing/databases/orient_test_bulk3
Destroying database4
database4.clean up
database4.delete db: local:D:/work/bay/testing/databases/orient_test_bulk4
database4.created: local:D:/work/bay/testing/databases/orient_test_bulk4
Thread: Thread[pool-2-thread-1,5,main] is serving database: database0
Thread: Thread[pool-2-thread-2,5,main] is serving database: database1
Thread: Thread[pool-2-thread-3,5,main] is serving database: database2
Thread: Thread[pool-2-thread-5,5,main] is serving database: database4
Setting thead local for thread: Thread[pool-2-thread-1,5,main] for serving database: database0
Thread: Thread[pool-2-thread-4,5,main] is serving database: database3
Setting thead local for thread: Thread[pool-2-thread-2,5,main] for serving database: database1
Setting thead local for thread: Thread[pool-2-thread-3,5,main] for serving database: database2
Setting thead local for thread: Thread[pool-2-thread-4,5,main] for serving database: database3
Setting thead local for thread: Thread[pool-2-thread-5,5,main] for serving database: database4
10000 => 10000 entries (x5 dbs) needed 17595ms
10000 => 10000 entries (x5 dbs) needed 17595ms
10000 => 10000 entries (x5 dbs) needed 17595ms
10000 => 10000 entries (x5 dbs) needed 17595ms
10000 => 10000 entries (x5 dbs) needed 17596ms
20000 => 10000 entries (x5 dbs) needed 15936ms
20000 => 10000 entries (x5 dbs) needed 15938ms
20000 => 10000 entries (x5 dbs) needed 15940ms
20000 => 10000 entries (x5 dbs) needed 15941ms
20000 => 10000 entries (x5 dbs) needed 15942ms
30000 => 10000 entries (x5 dbs) needed 17029ms
30000 => 10000 entries (x5 dbs) needed 17031ms
30000 => 10000 entries (x5 dbs) needed 17034ms
30000 => 10000 entries (x5 dbs) needed 17036ms
30000 => 10000 entries (x5 dbs) needed 17031ms
Exception in thread "pool-2-thread-2" com.orientechnologies.orient.core.exception.ODatabaseException: Error on saving record #1:53
    at com.orientechnologies.orient.core.db.raw.ODatabaseRaw.save(ODatabaseRaw.java:235)
    at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.executeSaveRecord(ODatabaseRecordAbstract.java:573)
    at com.orientechnologies.orient.core.tx.OTransactionNoTx.saveRecord(OTransactionNoTx.java:66)
    at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.save(ODatabaseRecordTx.java:211)
    at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.save(ODatabaseRecordTx.java:1)
    at com.orientechnologies.orient.core.record.ORecordAbstract.save(ORecordAbstract.java:282)
    at com.orientechnologies.orient.core.type.tree.generic.OTreeEntryDataProviderGeneric.save(OTreeEntryDataProviderGeneric.java:270)
    at com.orientechnologies.orient.core.type.tree.generic.OTreeEntryDataProviderGeneric.save(OTreeEntryDataProviderGeneric.java:259)
    at com.orientechnologies.orient.core.type.tree.OMVRBTreeEntryPersistent.save(OMVRBTreeEntryPersistent.java:185)
    at com.orientechnologies.orient.core.type.tree.OMVRBTreePersistent.commitChanges(OMVRBTreePersistent.java:448)
    at com.orientechnologies.orient.core.type.tree.OMVRBTreeDatabaseLazySave.lazySave(OMVRBTreeDatabaseLazySave.java:68)
    at com.orientechnologies.orient.core.type.tree.OMVRBTreeDatabaseLazySave.optimize(OMVRBTreeDatabaseLazySave.java:83)
    at com.orientechnologies.orient.core.type.tree.OMVRBTreePersistent.optimize(OMVRBTreePersistent.java:236)
    at com.orientechnologies.orient.core.type.tree.OMVRBTreePersistent.put(OMVRBTreePersistent.java:361)
    at com.orientechnologies.orient.core.index.OIndexUnique.put(OIndexUnique.java:47)
    at com.orientechnologies.orient.core.index.OIndexUnique.put(OIndexUnique.java:1)
    at com.orientechnologies.orient.core.tx.OTransactionNoTx.addIndexEntry(OTransactionNoTx.java:151)
    at com.orientechnologies.orient.core.index.OIndexTxAware.put(OIndexTxAware.java:77)
    at com.orientechnologies.orient.core.index.OIndexTxAware.put(OIndexTxAware.java:1)
    at com.orientechnologies.orient.core.index.OClassIndexManager.onRecordAfterCreate(OClassIndexManager.java:62)
    at com.orientechnologies.orient.core.hook.ODocumentHookAbstract.onTrigger(ODocumentHookAbstract.java:121)
    at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.callbackHooks(ODatabaseRecordAbstract.java:735)
    at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.executeSaveRecord(ODatabaseRecordAbstract.java:589)
    at com.orientechnologies.orient.core.tx.OTransactionNoTx.saveRecord(OTransactionNoTx.java:66)
    at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.save(ODatabaseRecordTx.java:211)
    at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.save(ODatabaseRecordTx.java:1)
    at com.orientechnologies.orient.core.db.ODatabaseRecordWrapperAbstract.save(ODatabaseRecordWrapperAbstract.java:218)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.save(ODatabaseDocumentTx.java:200)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.save(ODatabaseDocumentTx.java:1)
    at com.orientechnologies.orient.core.db.ODatabaseRecordWrapperAbstract.save(ODatabaseRecordWrapperAbstract.java:1)
    at com.orientechnologies.orient.core.record.ORecordAbstract.save(ORecordAbstract.java:282)
    at com.orientechnologies.orient.core.record.ORecordSchemaAwareAbstract.save(ORecordSchemaAwareAbstract.java:65)
    at com.orientechnologies.orient.core.record.ORecordSchemaAwareAbstract.save(ORecordSchemaAwareAbstract.java:55)
    at com.bayoda.orient.test.OrientDBThreadedDatabasesTest$DatabaseInstance.put(OrientDBThreadedDatabasesTest.java:330)
    at com.bayoda.orient.test.OrientDBThreadedDatabasesTest$Worker.run(OrientDBThreadedDatabasesTest.java:98)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.NullPointerException
    at com.orientechnologies.orient.core.storage.fs.OFileMMap.readLong(OFileMMap.java:107)
    at com.orientechnologies.orient.core.storage.impl.local.OClusterLocal.getPhysicalPosition(OClusterLocal.java:188)
    at com.orientechnologies.orient.core.storage.impl.local.OStorageLocal.updateRecord(OStorageLocal.java:1131)
    at com.orientechnologies.orient.core.storage.impl.local.OStorageLocal.updateRecord(OStorageLocal.java:600)
    at com.orientechnologies.orient.core.db.raw.ODatabaseRaw.save(ODatabaseRaw.java:229)
    ... 37 more






RemoteTestNG starting
Destroying database0
database0.clean up
database0.delete db: local:D:/work/bay/testing/databases/orient_test_bulk0
database0.created: local:D:/work/bay/testing/databases/orient_test_bulk0
Destroying database1
database1.clean up
database1.delete db: local:D:/work/bay/testing/databases/orient_test_bulk1
database1.created: local:D:/work/bay/testing/databases/orient_test_bulk1
Destroying database2
database2.clean up
database2.delete db: local:D:/work/bay/testing/databases/orient_test_bulk2
database2.created: local:D:/work/bay/testing/databases/orient_test_bulk2
Destroying database3
database3.clean up
database3.delete db: local:D:/work/bay/testing/databases/orient_test_bulk3
database3.created: local:D:/work/bay/testing/databases/orient_test_bulk3
Destroying database4
database4.clean up
database4.delete db: local:D:/work/bay/testing/databases/orient_test_bulk4
database4.created: local:D:/work/bay/testing/databases/orient_test_bulk4
Thread: Thread[pool-2-thread-1,5,main] is serving database: database0
Thread: Thread[pool-2-thread-2,5,main] is serving database: database1
Thread: Thread[pool-2-thread-3,5,main] is serving database: database2
Thread: Thread[pool-2-thread-5,5,main] is serving database: database4
Thread: Thread[pool-2-thread-4,5,main] is serving database: database3
Setting thead local for thread: Thread[pool-2-thread-1,5,main] for serving database: database0
Setting thead local for thread: Thread[pool-2-thread-2,5,main] for serving database: database1
Setting thead local for thread: Thread[pool-2-thread-3,5,main] for serving database: database2
Setting thead local for thread: Thread[pool-2-thread-4,5,main] for serving database: database3
Setting thead local for thread: Thread[pool-2-thread-5,5,main] for serving database: database4
10000 => 10000 entries (x5 dbs) needed 16374ms
10000 => 10000 entries (x5 dbs) needed 16373ms
10000 => 10000 entries (x5 dbs) needed 16374ms
10000 => 10000 entries (x5 dbs) needed 16374ms
10000 => 10000 entries (x5 dbs) needed 16365ms
20000 => 10000 entries (x5 dbs) needed 16112ms
20000 => 10000 entries (x5 dbs) needed 16113ms
20000 => 10000 entries (x5 dbs) needed 16117ms
20000 => 10000 entries (x5 dbs) needed 16122ms
20000 => 10000 entries (x5 dbs) needed 16132ms
30000 => 10000 entries (x5 dbs) needed 29107ms
30000 => 10000 entries (x5 dbs) needed 29110ms
30000 => 10000 entries (x5 dbs) needed 29111ms
30000 => 10000 entries (x5 dbs) needed 29101ms
30000 => 10000 entries (x5 dbs) needed 29091ms
40000 => 10000 entries (x5 dbs) needed 26225ms
40000 => 10000 entries (x5 dbs) needed 27099ms
40000 => 10000 entries (x5 dbs) needed 28256ms
40000 => 10000 entries (x5 dbs) needed 28262ms
40000 => 10000 entries (x5 dbs) needed 28667ms
02.12.2011 14:02:38 com.orientechnologies.common.log.OLogManager log
WARNUNG: Memory mapping error, try to reduce max memory to %d and retry...
java.io.IOException: Map failed
    at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:758)
    at com.orientechnologies.orient.core.storage.fs.OFileMMap.map(OFileMMap.java:369)
    at com.orientechnologies.orient.core.storage.fs.OMMapManager.mapBuffer(OMMapManager.java:376)
    at com.orientechnologies.orient.core.storage.fs.OMMapManager.request(OMMapManager.java:180)
    at com.orientechnologies.orient.core.storage.fs.OMMapManager.request(OMMapManager.java:105)
    at com.orientechnologies.orient.core.storage.fs.OFileMMap.readInt(OFileMMap.java:84)
    at com.orientechnologies.orient.core.storage.impl.local.ODataLocal.getRecord(ODataLocal.java:162)
    at com.orientechnologies.orient.core.storage.impl.local.OStorageLocal.readRecord(OStorageLocal.java:1100)
    at com.orientechnologies.orient.core.storage.impl.local.OStorageLocal.readRecord(OStorageLocal.java:597)
    at com.orientechnologies.orient.core.db.raw.ODatabaseRaw.read(ODatabaseRaw.java:207)
    at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.executeReadRecord(ODatabaseRecordAbstract.java:473)
    at com.orientechnologies.orient.core.tx.OTransactionNoTx.loadRecord(OTransactionNoTx.java:58)
    at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.load(ODatabaseRecordTx.java:195)
    at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.load(ODatabaseRecordAbstract.java:1)
    at com.orientechnologies.orient.core.db.ODatabaseRecordWrapperAbstract.load(ODatabaseRecordWrapperAbstract.java:181)
    at com.orientechnologies.orient.core.db.ODatabaseRecordWrapperAbstract.load(ODatabaseRecordWrapperAbstract.java:1)
    at com.bayoda.orient.test.OrientDBThreadedDatabasesTest$DatabaseInstance.get(OrientDBThreadedDatabasesTest.java:304)
    at com.bayoda.orient.test.OrientDBThreadedDatabasesTest$Worker.run(OrientDBThreadedDatabasesTest.java:102)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.OutOfMemoryError: Map failed
    at sun.nio.ch.FileChannelImpl.map0(Native Method)
    at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:755)
    ... 20 more




--
bayoda.com - Professional Online Backup Solutions for Small and Medium Sized Companies
OrientDBThreadedDatabasesTest.java

Luca Garulli

unread,
Dec 2, 2011, 3:35:29 PM12/2/11
to Michael Widmann, orient-...@googlegroups.com
Hi,
now seems fixed (SVN trunk).

I've run your test and since you're inserting a lot of data using multiple threads..well this really killed my notebook :-)

Suggestions:
  • disable l1 and l2 caches, or just use a massive insert intent
  • don't use mmap with so much data because cause a super overload at OS level. By setting "-Dfile.mmap.strategy=4" option it's slower but in the long time running consumes less resources

Lvc@
Reply all
Reply to author
Forward
0 new messages