Connection problems under load

399 views
Skip to first unread message

Olaf Geibig

unread,
Jul 16, 2012, 1:52:32 PM7/16/12
to orient-...@googlegroups.com
Hi,

I'm using v.1.1.0-SNAPSHOT build trunk@r5966. Document API. I'm working on a high performance webapplication using OrientDB. The webapp is running in load balanced tomcats, OrientDB on it's own server in the same network. My webapp offers inserting and updating data via a REST API, the webapp acquires database instances from a pool, and releases them in a finally statement as explained in the docs. Several clients use the REST API of the webapp and fire constantly, inserts and updates mixed. For some hours this all works fine but suddenly the pool runs out of database instances and there are strange errors in the log. It seems that the webapp's OrientDB client cannot get anything from the database server anymore. I have to reinitialize the whole connection to the database by restarting the webapp, to make it run again. I already create my own pool and set the size to 1000.

Cheers

Some log excerpts:

[2012-07-11 15:31:30,717] ERROR keyword.CanonicalController Adding keyword failed: Error on retrieving record #10:60840 (cluster: pt_br-keywords). keywordId=10:60887, canonicalId=11:5467
com.orientechnologies.orient.core.exception.ODatabaseException: Error on retrieving record #10:60840 (cluster: pt_br-keywords)
 at com.orientechnologies.orient.core.db.raw.ODatabaseRaw.read(ODatabaseRaw.java:234)
 at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.executeReadRecord(ODatabaseRecordAbstract.java:566)
 at com.orientechnologies.orient.core.tx.OTransactionNoTx.loadRecord(OTransactionNoTx.java:61)
 at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.load(ODatabaseRecordTx.java:192)
 at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.load(ODatabaseRecordTx.java:35)
 at com.orientechnologies.orient.core.record.impl.ODocument.field(ODocument.java:521)
 at com.glg.core.storage.orientdb.OrientdbEnhancer$_enhanceOrient_closure4.doCall(OrientdbEnhancer.groovy:28)
 at com.glg.console.keyword.CanonicalKeywordStorageService.addKeywordToCanonical(CanonicalKeywordStorageService.groovy:128)
 at com.glg.console.keyword.CanonicalController.addKeyword(CanonicalController.groovy:147)
 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:662)
Caused by: com.orientechnologies.common.io.OIOException: Received unread response from /85.195.92.203:2424 probably corrupted data from the network connection. Cleared dirty data in the buffer (3050 bytes): [ord@status:1,searchVolume:0l,locale:"pt_BR",dateAdded:1342013470475t,lastUpdated:,canonicalId:,isTop:true,cpc:0.0c,canonical:#11:5467,localSearchVolum...]
 at com.orientechnologies.common.log.OLogManager.error(OLogManager.java:133)
 at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinary.clearInput(OChannelBinary.java:312)
 at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynch.clearInput(OChannelBinaryAsynch.java:163)
 at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynch.beginResponse(OChannelBinaryAsynch.java:103)
 at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynch.beginResponse(OChannelBinaryAsynch.java:57)
 at com.orientechnologies.orient.client.remote.OStorageRemote.beginResponse(OStorageRemote.java:1538)
 at com.orientechnologies.orient.client.remote.OStorageRemote.readRecord(OStorageRemote.java:401)
 at com.orientechnologies.orient.client.remote.OStorageRemoteThread.readRecord(OStorageRemoteThread.java:145)
 at com.orientechnologies.orient.core.db.raw.ODatabaseRaw.read(ODatabaseRaw.java:228)
 ... 11 more

First this

[2012-07-12 03:55:30,057] DEBUG keyword.KeywordController Save [action:[GET:list, POST:save], controller:keyword, id:1
1:12636, name:cada de cal<C3><A7>ados dicas para ocasi<C3><A3>o, locale:pt_BR]
[2012-07-12 03:55:55,877] ERROR keyword.CanonicalController Adding keyword failed: Error on retrieving record #10:185909
 (cluster: pt_br-keywords). keywordId=10:197724, canonicalId=11:12489
com.orientechnologies.orient.core.exception.ODatabaseException: Error on retrieving record #10:185909 (cluster: pt_br-keywords)
 at com.orientechnologies.orient.core.db.raw.ODatabaseRaw.read(ODatabaseRaw.java:234)
 at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.executeReadRecord(ODatabaseRecordAbstract.java:566)
 at com.orientechnologies.orient.core.tx.OTransactionNoTx.loadRecord(OTransactionNoTx.java:61)
 at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.load(ODatabaseRecordTx.java:192)
 at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.load(ODatabaseRecordTx.java:35)
 at com.orientechnologies.orient.core.record.impl.ODocument.field(ODocument.java:521)
 at com.glg.core.storage.orientdb.OrientdbEnhancer$_enhanceOrient_closure4.doCall(OrientdbEnhancer.groovy:28)
 at com.glg.console.keyword.CanonicalKeywordStorageService.addKeywordToCanonical(CanonicalKeywordStorageService.groovy:128)
 at com.glg.console.keyword.CanonicalController.addKeyword(CanonicalController.groovy:147)
 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:662)
Caused by: com.orientechnologies.orient.core.exception.OStorageException: Error on read record #10:185909
 at com.orientechnologies.orient.client.remote.OStorageRemote.handleException(OStorageRemote.java:1163)
 at com.orientechnologies.orient.client.remote.OStorageRemote.readRecord(OStorageRemote.java:423)
 at com.orientechnologies.orient.client.remote.OStorageRemoteThread.readRecord(OStorageRemoteThread.java:145)
 at com.orientechnologies.orient.core.db.raw.ODatabaseRaw.read(ODatabaseRaw.java:228)
 ... 11 more
Caused by: java.lang.IllegalMonitorStateException
 at java.util.concurrent.locks.ReentrantLock$Sync.tryRelease(ReentrantLock.java:127)
 at java.util.concurrent.locks.AbstractQueuedSynchronizer.release(AbstractQueuedSynchronizer.java:1239)
 at java.util.concurrent.locks.ReentrantLock.unlock(ReentrantLock.java:431)
 at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynch.endResponse(OChannelBinaryAsynch.java:134)
 at com.orientechnologies.orient.client.remote.OStorageRemote.endResponse(OStorageRemote.java:1557)
 at com.orientechnologies.orient.client.remote.OStorageRemote.readRecord(OStorageRemote.java:419)
 ... 13 more

Later this

[2012-07-12 03:58:11,515] ERROR keyword.CanonicalController Adding keyword failed: The record with id '#2:0' not found. 
keywordId=10:197734, canonicalId=11:12747
com.orientechnologies.orient.core.exception.ORecordNotFoundException: The record with id '#2:0' not found
 at com.orientechnologies.orient.core.record.ORecordAbstract.reload(ORecordAbstract.java:263)
 at com.orientechnologies.orient.core.record.impl.ODocument.reload(ODocument.java:362)
 at com.orientechnologies.orient.core.type.ODocumentWrapper.reload(ODocumentWrapper.java:80)
 at com.orientechnologies.orient.core.type.ODocumentWrapperNoClass.reload(ODocumentWrapperNoClass.java:67)
 at com.orientechnologies.orient.core.metadata.schema.OSchemaShared$1.call(OSchemaShared.java:378)
 at com.orientechnologies.orient.core.metadata.schema.OSchemaShared$1.call(OSchemaShared.java:373)
 at com.orientechnologies.orient.core.storage.OStorageAbstract.callInLock(OStorageAbstract.java:162)
 at com.orientechnologies.orient.client.remote.OStorageRemoteThread.callInLock(OStorageRemoteThread.java:355)
 at com.orientechnologies.orient.core.metadata.schema.OSchemaShared.reload(OSchemaShared.java:373)
 at com.orientechnologies.orient.core.metadata.schema.OSchemaProxy.reload(OSchemaProxy.java:140)
 at com.orientechnologies.orient.core.metadata.OMetadata.reload(OMetadata.java:142)
 at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTxPooled.reuse(ODatabaseDocumentTxPooled.java:47)
 at com.orientechnologies.orient.core.db.ODatabasePoolBase$1.reuseResource(ODatabasePoolBase.java:72)
 at com.orientechnologies.orient.core.db.ODatabasePoolBase$1.reuseResource(ODatabasePoolBase.java:56)
 at com.orientechnologies.common.concur.resource.OResourcePool.getResource(OResourcePool.java:56)
 at com.orientechnologies.orient.core.db.ODatabasePoolAbstract.acquire(ODatabasePoolAbstract.java:64)
 at com.orientechnologies.orient.core.db.ODatabasePoolAbstract.acquire(ODatabasePoolAbstract.java:52)
 at com.orientechnologies.orient.core.db.ODatabasePoolBase.acquire(ODatabasePoolBase.java:114)
 at com.glg.core.storage.orientdb.OrientdbDatabaseHolder.acquireDatabase(OrientdbDatabaseHolder.groovy:94)
 at com.glg.core.storage.orientdb.OrientdbDatabaseHolder.fetchDatabase(OrientdbDatabaseHolder.groovy:64)
 at com.glg.core.storage.orientdb.OrientdbDatabaseHolder.withOrientdb(OrientdbDatabaseHolder.groovy:37)
 at com.glg.core.storage.orientdb.OrientdbEnhancer$_enhance_closure2.doCall(OrientdbEnhancer.groovy:14)
 at com.glg.console.keyword.CanonicalKeywordStorageService.getById(CanonicalKeywordStorageService.groovy:72)
 at com.glg.console.keyword.CanonicalController.addKeyword(CanonicalController.groovy:133)
 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:662)
Caused by: com.orientechnologies.orient.core.exception.ODatabaseException: Error on retrieving record #2:0 (cluster: default)
 at com.orientechnologies.orient.core.db.raw.ODatabaseRaw.read(ODatabaseRaw.java:234)
 at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.executeReadRecord(ODatabaseRecordAbstract.java:566)
 at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.reload(ODatabaseRecordAbstract.java:244)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.reload(ODatabaseRecordAbstract.java:69)
 at com.orientechnologies.orient.core.record.ORecordAbstract.reload(ORecordAbstract.java:256)
 ... 26 more
Caused by: com.orientechnologies.orient.core.exception.OStorageException: Error on read record #2:0
 at com.orientechnologies.orient.client.remote.OStorageRemote.handleException(OStorageRemote.java:1163)
 at com.orientechnologies.orient.client.remote.OStorageRemote.readRecord(OStorageRemote.java:423)
 at com.orientechnologies.orient.client.remote.OStorageRemoteThread.readRecord(OStorageRemoteThread.java:145)
 at com.orientechnologies.orient.core.db.raw.ODatabaseRaw.read(ODatabaseRaw.java:228)
 ... 30 more
Caused by: java.lang.IllegalMonitorStateException
 at java.util.concurrent.locks.ReentrantLock$Sync.tryRelease(ReentrantLock.java:127)
 at java.util.concurrent.locks.AbstractQueuedSynchronizer.release(AbstractQueuedSynchronizer.java:1239)
 at java.util.concurrent.locks.ReentrantLock.unlock(ReentrantLock.java:431)
 at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynch.endResponse(OChannelBinaryAsynch.java:134)
 at com.orientechnologies.orient.client.remote.OStorageRemote.endResponse(OStorageRemote.java:1557)
 at com.orientechnologies.orient.client.remote.OStorageRemote.readRecord(OStorageRemote.java:419)
 ... 32 more

Luca Garulli

unread,
Jul 16, 2012, 2:03:31 PM7/16/12
to orient-...@googlegroups.com
Hi,
this sounds strange. Seems that some connection remain pending locking resources at server-side. Could you provide a thread dump of the server in this situation? Probably to get it faster limit the pool to 10 connections.

Lvc@

Olaf Geibig

unread,
Jul 16, 2012, 3:19:49 PM7/16/12
to orient-...@googlegroups.com
Here is a thread dump:

Full thread dump Java HotSpot(TM) 64-Bit Server VM (23.1-b03 mixed mode):

"OrientDB <- BinaryClient (/127.0.0.1:55903)" daemon prio=10 tid=0x00000000034ee000 nid=0xa73 waiting on condition [0x00007fe02e514000]
   java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00000000c05b00d0> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireNanos(AbstractQueuedSynchronizer.java:929)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireNanos(AbstractQueuedSynchronizer.java:1245)
at java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.tryLock(ReentrantReadWriteLock.java:1115)
at com.orientechnologies.common.concur.resource.OSharedResourceAdaptive.acquireExclusiveLock(OSharedResourceAdaptive.java:68)
at com.orientechnologies.common.concur.resource.OSharedResourceAdaptiveExternal.acquireExclusiveLock(OSharedResourceAdaptiveExternal.java:31)
at com.orientechnologies.orient.core.index.OIndexOneValue.get(OIndexOneValue.java:54)
at com.orientechnologies.orient.core.index.OIndexOneValue.get(OIndexOneValue.java:47)
at com.orientechnologies.orient.core.index.OIndexAbstractDelegate.get(OIndexAbstractDelegate.java:62)
at com.orientechnologies.orient.core.index.OIndexTxAwareOneValue.get(OIndexTxAwareOneValue.java:62)
at com.orientechnologies.orient.core.index.OIndexTxAwareOneValue.checkEntry(OIndexTxAwareOneValue.java:47)
at com.orientechnologies.orient.core.index.OClassIndexManager.checkIndexedPropertiesOnUpdate(OClassIndexManager.java:443)
at com.orientechnologies.orient.core.index.OClassIndexManager.onRecordBeforeUpdate(OClassIndexManager.java:93)
at com.orientechnologies.orient.core.hook.ODocumentHookAbstract.onTrigger(ODocumentHookAbstract.java:165)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.callbackHooks(ODatabaseRecordAbstract.java:880)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.executeSaveRecord(ODatabaseRecordAbstract.java:648)
at com.orientechnologies.orient.core.tx.OTransactionNoTx.saveRecord(OTransactionNoTx.java:72)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.save(ODatabaseRecordTx.java:221)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.save(ODatabaseRecordTx.java:204)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.save(ODatabaseRecordTx.java:35)
at com.orientechnologies.orient.core.db.ODatabaseRecordWrapperAbstract.save(ODatabaseRecordWrapperAbstract.java:242)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.save(ODatabaseDocumentTx.java:268)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.save(ODatabaseDocumentTx.java:216)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.save(ODatabaseDocumentTx.java:46)
at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.updateRecord(OBinaryNetworkProtocolAbstract.java:337)
at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.updateRecord(ONetworkProtocolBinary.java:1023)
at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.executeRequest(ONetworkProtocolBinary.java:239)
at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:116)
at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:43)

"OrientDB <- BinaryClient (/127.0.0.1:55902)" daemon prio=10 tid=0x000000000274f000 nid=0xa37 runnable [0x00007fe02e70a000]
   java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:150)
at java.net.SocketInputStream.read(SocketInputStream.java:121)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
at java.io.BufferedInputStream.read(BufferedInputStream.java:254)
- locked <0x00000000c0664e90> (a java.io.BufferedInputStream)
at java.io.DataInputStream.readByte(DataInputStream.java:265)
at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinary.readByte(OChannelBinary.java:72)
at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:111)
at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:43)

"OrientDB <- BinaryClient (/127.0.0.1:55901)" daemon prio=10 tid=0x000000000274e000 nid=0xa36 runnable [0x00007fe02eb0e000]
   java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:150)
at java.net.SocketInputStream.read(SocketInputStream.java:121)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
at java.io.BufferedInputStream.read(BufferedInputStream.java:254)
- locked <0x00000000c066cfe0> (a java.io.BufferedInputStream)
at java.io.DataInputStream.readByte(DataInputStream.java:265)
at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinary.readByte(OChannelBinary.java:72)
at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:111)
at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:43)

"OrientDB <- BinaryClient (/127.0.0.1:55900)" daemon prio=10 tid=0x0000000002595800 nid=0xa04 runnable [0x00007fe02ea0c000]
   java.lang.Thread.State: RUNNABLE
at com.orientechnologies.orient.core.serialization.serializer.binary.impl.OStringSerializer.deserialize(OStringSerializer.java:53)
at com.orientechnologies.orient.core.serialization.serializer.binary.impl.OStringSerializer.deserialize(OStringSerializer.java:30)
at com.orientechnologies.orient.core.type.tree.provider.OMVRBTreeMapEntryProvider.keyFromStream(OMVRBTreeMapEntryProvider.java:556)
at com.orientechnologies.orient.core.type.tree.provider.OMVRBTreeMapEntryProvider.getKeyAt(OMVRBTreeMapEntryProvider.java:69)
at com.orientechnologies.orient.core.type.tree.OMVRBTreeEntryPersistent.getKeyAt(OMVRBTreeEntryPersistent.java:540)
at com.orientechnologies.common.collection.OMVRBTreeEntry.getKey(OMVRBTreeEntry.java:121)
at com.orientechnologies.common.collection.OMVRBTreeEntry.getLastKey(OMVRBTreeEntry.java:285)
at com.orientechnologies.common.collection.OMVRBTree.getEntry(OMVRBTree.java:420)
at com.orientechnologies.common.collection.OMVRBTree.getEntry(OMVRBTree.java:351)
at com.orientechnologies.common.collection.OMVRBTree.get(OMVRBTree.java:276)
at com.orientechnologies.orient.core.type.tree.OMVRBTreePersistent.get(OMVRBTreePersistent.java:609)
at com.orientechnologies.orient.core.index.OIndexOneValue.get(OIndexOneValue.java:57)
at com.orientechnologies.orient.core.index.OIndexOneValue.get(OIndexOneValue.java:47)
at com.orientechnologies.orient.core.index.OIndexAbstractDelegate.get(OIndexAbstractDelegate.java:62)
at com.orientechnologies.orient.core.index.OIndexTxAwareOneValue.get(OIndexTxAwareOneValue.java:62)
at com.orientechnologies.orient.core.index.OIndexTxAwareOneValue.checkEntry(OIndexTxAwareOneValue.java:47)
at com.orientechnologies.orient.core.index.OClassIndexManager.checkIndexedPropertiesOnUpdate(OClassIndexManager.java:443)
at com.orientechnologies.orient.core.index.OClassIndexManager.onRecordBeforeUpdate(OClassIndexManager.java:93)
at com.orientechnologies.orient.core.hook.ODocumentHookAbstract.onTrigger(ODocumentHookAbstract.java:165)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.callbackHooks(ODatabaseRecordAbstract.java:880)
at com.orientechnologies.orient.core.tx.OTransactionOptimistic.addRecord(OTransactionOptimistic.java:206)
at com.orientechnologies.orient.server.tx.OTransactionOptimisticProxy.begin(OTransactionOptimisticProxy.java:136)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.begin(ODatabaseRecordTx.java:91)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.begin(ODatabaseRecordTx.java:35)
at com.orientechnologies.orient.core.db.ODatabaseRecordWrapperAbstract.begin(ODatabaseRecordWrapperAbstract.java:126)
at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.commit(ONetworkProtocolBinary.java:812)
at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.executeRequest(ONetworkProtocolBinary.java:255)
at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:116)
at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:43)

"OrientDB <- BinaryClient (/127.0.0.1:55899)" daemon prio=10 tid=0x0000000002627000 nid=0x9e9 runnable [0x00007fe0388d5000]
   java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:150)
at java.net.SocketInputStream.read(SocketInputStream.java:121)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
at java.io.BufferedInputStream.read(BufferedInputStream.java:254)
- locked <0x00000000c034c2b0> (a java.io.BufferedInputStream)
at java.io.DataInputStream.readByte(DataInputStream.java:265)
at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinary.readByte(OChannelBinary.java:72)
at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:111)
at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:43)

"OrientDB <- BinaryClient (/127.0.0.1:55898)" daemon prio=10 tid=0x00000000022fc000 nid=0x9e7 runnable [0x00007fe037ad8000]
   java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:150)
at java.net.SocketInputStream.read(SocketInputStream.java:121)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
at java.io.BufferedInputStream.read(BufferedInputStream.java:254)
- locked <0x00000000c031e210> (a java.io.BufferedInputStream)
at java.io.DataInputStream.readByte(DataInputStream.java:265)
at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinary.readByte(OChannelBinary.java:72)
at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:111)
at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:43)

"DestroyJavaVM" prio=10 tid=0x00007fe03c289000 nid=0x8ba waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"OrientDB ONetworkProtocolHttpDb listen at 0.0.0.0:2480-2490" prio=10 tid=0x00007fe03c287800 nid=0x8d0 runnable [0x00007fe0389d6000]
   java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398)
at java.net.ServerSocket.implAccept(ServerSocket.java:522)
at java.net.ServerSocket.accept(ServerSocket.java:490)
at com.orientechnologies.orient.server.network.OServerNetworkListener.run(OServerNetworkListener.java:140)

"OrientDB ONetworkProtocolBinary listen at 0.0.0.0:2424-2430" prio=10 tid=0x00007fe03c281000 nid=0x8cd runnable [0x00007fe038ad7000]
   java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398)
at java.net.ServerSocket.implAccept(ServerSocket.java:522)
at java.net.ServerSocket.accept(ServerSocket.java:490)
at com.orientechnologies.orient.server.network.OServerNetworkListener.run(OServerNetworkListener.java:140)

"OrientDB MemoryWatchDog" daemon prio=10 tid=0x00007fe03c1eb000 nid=0x8cc in Object.wait() [0x00007fe0393f8000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000c012ab38> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
- locked <0x00000000c012ab38> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
at com.orientechnologies.orient.core.memory.OMemoryWatchDog.run(OMemoryWatchDog.java:76)

"Timer-0" daemon prio=10 tid=0x00007fe03c1c5800 nid=0x8cb in Object.wait() [0x00007fe0394f9000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000c00fa510> (a java.util.TaskQueue)
at java.util.TimerThread.mainLoop(Timer.java:552)
- locked <0x00000000c00fa510> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:505)

"Service Thread" daemon prio=10 tid=0x00007fe03c055000 nid=0x8c9 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=10 tid=0x00007fe03c052800 nid=0x8c8 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=10 tid=0x00007fe03c04f800 nid=0x8c7 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x00007fe03c04d800 nid=0x8c6 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x00007fe03c001000 nid=0x8c5 in Object.wait() [0x00007fe03a2da000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000c0159cf8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
- locked <0x00000000c0159cf8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:177)

"Reference Handler" daemon prio=10 tid=0x0000000002373000 nid=0x8c4 in Object.wait() [0x00007fe03a3db000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000c01597d0> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:503)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
- locked <0x00000000c01597d0> (a java.lang.ref.Reference$Lock)

"VM Thread" prio=10 tid=0x000000000236b800 nid=0x8c3 runnable 

"GC task thread#0 (ParallelGC)" prio=10 tid=0x00000000022e8000 nid=0x8bb runnable 

"GC task thread#1 (ParallelGC)" prio=10 tid=0x00000000022ea000 nid=0x8bc runnable 

"GC task thread#2 (ParallelGC)" prio=10 tid=0x00000000022ec000 nid=0x8bd runnable 

"GC task thread#3 (ParallelGC)" prio=10 tid=0x00000000022ee000 nid=0x8be runnable 

"GC task thread#4 (ParallelGC)" prio=10 tid=0x00000000022ef800 nid=0x8bf runnable 

"GC task thread#5 (ParallelGC)" prio=10 tid=0x00000000022f1800 nid=0x8c0 runnable 

"GC task thread#6 (ParallelGC)" prio=10 tid=0x00000000022f3800 nid=0x8c1 runnable 

"GC task thread#7 (ParallelGC)" prio=10 tid=0x00000000022f5000 nid=0x8c2 runnable 

"VM Periodic Task Thread" prio=10 tid=0x00007fe03c060000 nid=0x8ca waiting on condition 

JNI global references: 445

Heap
 PSYoungGen      total 262912K, used 52675K [0x00000000eaab0000, 0x00000000fff60000, 0x0000000100000000)
  eden space 262848K, 20% used [0x00000000eaab0000,0x00000000ede10e38,0x00000000fab60000)
  from space 64K, 100% used [0x00000000fff50000,0x00000000fff60000,0x00000000fff60000)
  to   space 128K, 0% used [0x00000000fff20000,0x00000000fff20000,0x00000000fff40000)
 ParOldGen       total 100096K, used 32774K [0x00000000c0000000, 0x00000000c61c0000, 0x00000000eaab0000)
  object space 100096K, 32% used [0x00000000c0000000,0x00000000c2001a18,0x00000000c61c0000)
 PSPermGen       total 30336K, used 15389K [0x00000000bae00000, 0x00000000bcba0000, 0x00000000c0000000)
  object space 30336K, 50% used [0x00000000bae00000,0x00000000bbd077e8,0x00000000bcba0000)

2012-07-16 21:05:49
Full thread dump Java HotSpot(TM) 64-Bit Server VM (23.1-b03 mixed mode):

"OrientDB <- BinaryClient (/127.0.0.1:55903)" daemon prio=10 tid=0x00000000034ee000 nid=0xa73 waiting on condition [0x00007fe02e514000]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00000000c00f9380> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:964)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1282)
at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:731)
at com.orientechnologies.common.concur.resource.OSharedResourceAbstract.acquireSharedLock(OSharedResourceAbstract.java:31)
at com.orientechnologies.orient.server.OClientConnectionManager.getConnection(OClientConnectionManager.java:105)
at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.onBeforeRequest(ONetworkProtocolBinary.java:106)
at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:114)
at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:43)

"OrientDB <- BinaryClient (/127.0.0.1:55902)" daemon prio=10 tid=0x000000000274f000 nid=0xa37 waiting on condition [0x00007fe02e709000]
   java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00000000c05b00d0> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireNanos(AbstractQueuedSynchronizer.java:929)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireNanos(AbstractQueuedSynchronizer.java:1245)
at java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.tryLock(ReentrantReadWriteLock.java:1115)
at com.orientechnologies.common.concur.resource.OSharedResourceAdaptive.acquireExclusiveLock(OSharedResourceAdaptive.java:68)
at com.orientechnologies.common.concur.resource.OSharedResourceAdaptiveExternal.acquireExclusiveLock(OSharedResourceAdaptiveExternal.java:31)
at com.orientechnologies.orient.core.index.OIndexMVRBTreeAbstract.lazySave(OIndexMVRBTreeAbstract.java:497)
at com.orientechnologies.orient.core.index.OIndexMVRBTreeAbstract.flush(OIndexMVRBTreeAbstract.java:98)
at com.orientechnologies.orient.core.index.OIndexManagerAbstract.flush(OIndexManagerAbstract.java:141)
at com.orientechnologies.orient.core.index.OIndexManagerProxy.flush(OIndexManagerProxy.java:97)
at com.orientechnologies.orient.core.metadata.OMetadata.close(OMetadata.java:152)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.close(ODatabaseRecordAbstract.java:199)
at com.orientechnologies.orient.core.db.ODatabaseWrapperAbstract.close(ODatabaseWrapperAbstract.java:67)
at com.orientechnologies.orient.server.OClientConnection.close(OClientConnection.java:46)
at com.orientechnologies.orient.server.OClientConnectionManager.disconnect(OClientConnectionManager.java:138)
at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.closeDatabase(ONetworkProtocolBinary.java:742)
at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.executeRequest(ONetworkProtocolBinary.java:175)
at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:116)
at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:43)

"OrientDB <- BinaryClient (/127.0.0.1:55901)" daemon prio=10 tid=0x000000000274e000 nid=0xa36 waiting on condition [0x00007fe02eb0e000]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00000000c00f9380> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197)
at java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:945)
at com.orientechnologies.common.concur.resource.OSharedResourceAbstract.acquireExclusiveLock(OSharedResourceAbstract.java:39)
at com.orientechnologies.orient.server.OClientConnectionManager.disconnect(OClientConnectionManager.java:133)
at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.closeDatabase(ONetworkProtocolBinary.java:742)
at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.executeRequest(ONetworkProtocolBinary.java:175)
at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:116)
at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:43)

"OrientDB <- BinaryClient (/127.0.0.1:55900)" daemon prio=10 tid=0x0000000002595800 nid=0xa04 runnable [0x00007fe02ea0c000]
   java.lang.Thread.State: RUNNABLE
at com.orientechnologies.common.collection.OMVRBTree.predecessor(OMVRBTree.java:2275)
at com.orientechnologies.common.collection.OMVRBTree.getEntry(OMVRBTree.java:424)
at com.orientechnologies.common.collection.OMVRBTree.getEntry(OMVRBTree.java:351)
at com.orientechnologies.common.collection.OMVRBTree.get(OMVRBTree.java:276)
at com.orientechnologies.orient.core.type.tree.OMVRBTreePersistent.get(OMVRBTreePersistent.java:609)
at com.orientechnologies.orient.core.index.OIndexOneValue.get(OIndexOneValue.java:57)
at com.orientechnologies.orient.core.index.OIndexOneValue.get(OIndexOneValue.java:47)
at com.orientechnologies.orient.core.index.OIndexAbstractDelegate.get(OIndexAbstractDelegate.java:62)
at com.orientechnologies.orient.core.index.OIndexTxAwareOneValue.get(OIndexTxAwareOneValue.java:62)
at com.orientechnologies.orient.core.index.OIndexTxAwareOneValue.checkEntry(OIndexTxAwareOneValue.java:47)
at com.orientechnologies.orient.core.index.OClassIndexManager.checkIndexedPropertiesOnUpdate(OClassIndexManager.java:443)
at com.orientechnologies.orient.core.index.OClassIndexManager.onRecordBeforeUpdate(OClassIndexManager.java:93)
at com.orientechnologies.orient.core.hook.ODocumentHookAbstract.onTrigger(ODocumentHookAbstract.java:165)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordAbstract.callbackHooks(ODatabaseRecordAbstract.java:880)
at com.orientechnologies.orient.core.tx.OTransactionOptimistic.addRecord(OTransactionOptimistic.java:206)
at com.orientechnologies.orient.server.tx.OTransactionOptimisticProxy.begin(OTransactionOptimisticProxy.java:136)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.begin(ODatabaseRecordTx.java:91)
at com.orientechnologies.orient.core.db.record.ODatabaseRecordTx.begin(ODatabaseRecordTx.java:35)
at com.orientechnologies.orient.core.db.ODatabaseRecordWrapperAbstract.begin(ODatabaseRecordWrapperAbstract.java:126)
at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.commit(ONetworkProtocolBinary.java:812)
at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.executeRequest(ONetworkProtocolBinary.java:255)
at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:116)
at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:43)

"OrientDB <- BinaryClient (/127.0.0.1:55899)" daemon prio=10 tid=0x0000000002627000 nid=0x9e9 waiting on condition [0x00007fe0388d5000]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00000000c00f9380> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:964)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1282)
at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:731)
at com.orientechnologies.common.concur.resource.OSharedResourceAbstract.acquireSharedLock(OSharedResourceAbstract.java:31)
at com.orientechnologies.orient.server.OClientConnectionManager.getConnection(OClientConnectionManager.java:105)
at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.onBeforeRequest(ONetworkProtocolBinary.java:106)
at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:114)
at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:43)

"OrientDB <- BinaryClient (/127.0.0.1:55898)" daemon prio=10 tid=0x00000000022fc000 nid=0x9e7 runnable [0x00007fe037ad8000]
   java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:150)
at java.net.SocketInputStream.read(SocketInputStream.java:121)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
at java.io.BufferedInputStream.read(BufferedInputStream.java:254)
- locked <0x00000000c031e210> (a java.io.BufferedInputStream)
at java.io.DataInputStream.readByte(DataInputStream.java:265)
at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinary.readByte(OChannelBinary.java:72)
at com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:111)
at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:43)

"DestroyJavaVM" prio=10 tid=0x00007fe03c289000 nid=0x8ba waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"OrientDB ONetworkProtocolHttpDb listen at 0.0.0.0:2480-2490" prio=10 tid=0x00007fe03c287800 nid=0x8d0 runnable [0x00007fe0389d6000]
   java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398)
at java.net.ServerSocket.implAccept(ServerSocket.java:522)
at java.net.ServerSocket.accept(ServerSocket.java:490)
at com.orientechnologies.orient.server.network.OServerNetworkListener.run(OServerNetworkListener.java:140)

"OrientDB ONetworkProtocolBinary listen at 0.0.0.0:2424-2430" prio=10 tid=0x00007fe03c281000 nid=0x8cd runnable [0x00007fe038ad7000]
   java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398)
at java.net.ServerSocket.implAccept(ServerSocket.java:522)
at java.net.ServerSocket.accept(ServerSocket.java:490)
at com.orientechnologies.orient.server.network.OServerNetworkListener.run(OServerNetworkListener.java:140)

"OrientDB MemoryWatchDog" daemon prio=10 tid=0x00007fe03c1eb000 nid=0x8cc in Object.wait() [0x00007fe0393f8000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000c012ab38> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
- locked <0x00000000c012ab38> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
at com.orientechnologies.orient.core.memory.OMemoryWatchDog.run(OMemoryWatchDog.java:76)

"Timer-0" daemon prio=10 tid=0x00007fe03c1c5800 nid=0x8cb waiting on condition [0x00007fe0394f9000]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00000000c00f9380> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197)
at java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:945)
at com.orientechnologies.common.concur.resource.OSharedResourceAbstract.acquireExclusiveLock(OSharedResourceAbstract.java:39)
at com.orientechnologies.orient.server.OClientConnectionManager.access$000(OClientConnectionManager.java:41)
at com.orientechnologies.orient.server.OClientConnectionManager$1.run(OClientConnectionManager.java:54)
at java.util.TimerThread.mainLoop(Timer.java:555)
at java.util.TimerThread.run(Timer.java:505)

"Service Thread" daemon prio=10 tid=0x00007fe03c055000 nid=0x8c9 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=10 tid=0x00007fe03c052800 nid=0x8c8 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=10 tid=0x00007fe03c04f800 nid=0x8c7 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x00007fe03c04d800 nid=0x8c6 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x00007fe03c001000 nid=0x8c5 in Object.wait() [0x00007fe03a2da000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000c0159cf8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
- locked <0x00000000c0159cf8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:177)

"Reference Handler" daemon prio=10 tid=0x0000000002373000 nid=0x8c4 in Object.wait() [0x00007fe03a3db000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000c01597d0> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:503)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
- locked <0x00000000c01597d0> (a java.lang.ref.Reference$Lock)

"VM Thread" prio=10 tid=0x000000000236b800 nid=0x8c3 runnable 

"GC task thread#0 (ParallelGC)" prio=10 tid=0x00000000022e8000 nid=0x8bb runnable 

"GC task thread#1 (ParallelGC)" prio=10 tid=0x00000000022ea000 nid=0x8bc runnable 

"GC task thread#2 (ParallelGC)" prio=10 tid=0x00000000022ec000 nid=0x8bd runnable 

"GC task thread#3 (ParallelGC)" prio=10 tid=0x00000000022ee000 nid=0x8be runnable 

"GC task thread#4 (ParallelGC)" prio=10 tid=0x00000000022ef800 nid=0x8bf runnable 

"GC task thread#5 (ParallelGC)" prio=10 tid=0x00000000022f1800 nid=0x8c0 runnable 

"GC task thread#6 (ParallelGC)" prio=10 tid=0x00000000022f3800 nid=0x8c1 runnable 

"GC task thread#7 (ParallelGC)" prio=10 tid=0x00000000022f5000 nid=0x8c2 runnable 

"VM Periodic Task Thread" prio=10 tid=0x00007fe03c060000 nid=0x8ca waiting on condition 

JNI global references: 445

Heap
 PSYoungGen      total 204352K, used 175861K [0x00000000eaab0000, 0x00000000fff40000, 0x0000000100000000)
  eden space 204224K, 86% used [0x00000000eaab0000,0x00000000f5655718,0x00000000f7220000)
  from space 128K, 75% used [0x00000000fff20000,0x00000000fff38000,0x00000000fff40000)
  to   space 192K, 0% used [0x00000000ffee0000,0x00000000ffee0000,0x00000000fff10000)
 ParOldGen       total 100096K, used 32878K [0x00000000c0000000, 0x00000000c61c0000, 0x00000000eaab0000)
  object space 100096K, 32% used [0x00000000c0000000,0x00000000c201ba18,0x00000000c61c0000)
 PSPermGen       total 30336K, used 15389K [0x00000000bae00000, 0x00000000bcba0000, 0x00000000c0000000)
  object space 30336K, 50% used [0x00000000bae00000,0x00000000bbd077e8,0x00000000bcba0000)

Internal server error
Timeout on acquiring exclusive lock against resource of class: class com.orientechnologies.orient.core.index.OIndexUnique with timeout=5000
-> com.orientechnologies.common.concur.resource.OSharedResourceAdaptive.acquireExclusiveLock(OSharedResourceAdaptive.java:88)
-> com.orientechnologies.common.concur.resource.OSharedResourceAdaptiveExternal.acquireExclusiveLock(OSharedResourceAdaptiveExternal.java:31)
-> com.orientechnologies.orient.core.index.OIndexMVRBTreeAbstract.lazySave(OIndexMVRBTreeAbstract.java:497)
-> com.orientechnologies.orient.core.index.OIndexMVRBTreeAbstract.flush(OIndexMVRBTreeAbstract.java:98)
-> com.orientechnologies.orient.core.index.OIndexManagerAbstract.flush(OIndexManagerAbstract.java:141)
-> com.orientechnologies.orient.core.index.OIndexManagerProxy.flush(OIndexManagerProxy.java:97)
-> com.orientechnologies.orient.core.metadata.OMetadata.close(OMetadata.java:152)
-> com.orientechnologies.orient.core.db.document.ODatabaseDocumentTxPooled.close(ODatabaseDocumentTxPooled.java:82)
-> com.orientechnologies.orient.server.db.OSharedDocumentDatabase.release(OSharedDocumentDatabase.java:34)
-> com.orientechnologies.orient.server.network.protocol.http.command.OServerCommandAuthenticatedDbAbstract.authenticate(OServerCommandAuthenticatedDbAbstract.java:119)
-> com.orientechnologies.orient.server.network.protocol.http.command.OServerCommandAuthenticatedDbAbstract.beforeExecute(OServerCommandAuthenticatedDbAbstract.java:67)
-> com.orientechnologies.orient.server.network.protocol.http.command.get.OServerCommandGetConnect.beforeExecute(OServerCommandGetConnect.java:69)
-> com.orientechnologies.orient.server.network.protocol.http.ONetworkProtocolHttpAbstract.service(ONetworkProtocolHttpAbstract.java:139)
-> com.orientechnologies.orient.server.network.protocol.http.ONetworkProtocolHttpAbstract.execute(ONetworkProtocolHttpAbstract.java:477)
-> com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:43)

Luca Garulli

unread,
Jul 17, 2012, 4:17:02 AM7/17/12
to orient-...@googlegroups.com
Hi KRP,
I just tried your test case but seems all fine:

All threads were Successful!!!
Finished loop 300
Finished all loops!
Exiting App...

Any idea about to reproduce it? Probably changing some values? Attached the slightly modified test case with the creation of the "Data" class and some values.

Lvc@

On 17 July 2012 05:33, KRP <kea...@gmail.com> wrote:
Hi Luca,

We've been running into what seems like the exact same issue as Olaf with the exact same errors with almost the same type of environment. We've tried adjusting many of the default OrientDB configuration values on both the client and server but it only extends the time until the "SEVERE unread response" error finally appears in the logs and all the database connections hang. We've also tried running the latest 1.1.0-SNAPSHOT from trunk for both the client and server.

As part of trying to troubleshoot this issue I created a self-contained app that throws this error.
  • The sql statements to seed the data for the database are in the comment at the begging of the Java class.
  • An example orientdb-client-log.properties is in a comment in the init method.
  • The error appears within about 2-3 minutes of running this app or within about 20-30 minutes if all default values are used.
I don't know if this is relevant info but the SEVERE unread response error always happens right after Session -2147483648 (and there is always one of these) increments beyond the NETWORK_BINARY_READ_RESPONSE_MAX_TIMES number. It never seems to happen after one of the other session numbers used for data transfer.

2012-07-15 07:56:06:325 FINE /127.0.0.1:55878 - Session 496 skip response, it is for 504 [OChannelBinaryClient]
2012-07-15 07:56:06:326 FINE /127.0.0.1:55878 - Session 485 skip response, it is for 504 [OChannelBinaryClient]
2012-07-15 07:56:06:326 FINE /127.0.0.1:55878 - Session 510 skip response, it is for 504 [OChannelBinaryClient]
2012-07-15 07:56:06:326 FINE /127.0.0.1:55878 - Session -2147483648 skip response, it is for 504 [OChannelBinaryClient]
2012-07-15 07:56:06:331 SEVE Received unread response from /127.0.0.1:55878 probably corrupted data from the network connection. Cleared dirty data in the buffer (2837 bytes): [

After the unread response error there is always at least a 15 second gap with no more log messages.

2012-07-15 07:56:21:320 FINE [4] i=49 list.size()=0 [UnreadResponseTestApp$DataWorker]Failed to select data...
Error on executing command: OSQLQuery [text=SELECT metadata FROM Data]

Hopefully some of this and possibly the attached app can be useful in troubleshooting the issue.

Cheers,
KRP

--
 
 
 

UnreadResponseTestApp.java

Luca Garulli

unread,
Jul 17, 2012, 6:57:35 AM7/17/12
to orient-...@googlegroups.com
This seems the most critical problem of 1.1.0. Please help me to reproduce it.

Lvc@

Fabrizio Fortino

unread,
Jul 17, 2012, 9:33:40 AM7/17/12
to orient-...@googlegroups.com
Hi Luca,

Same problem here. I am not able to create a test case to reproduce it (there is some race condition). Can I enable some specific log  on client/server side to help you to figure out the cause of the problem?

Cheers,
Fabrizio

On Tuesday, July 17, 2012 12:57:35 PM UTC+2, Lvc@ wrote:
This seems the most critical problem of 1.1.0. Please help me to reproduce it.

Lvc@


Hi KRP,
I just tried your test case but seems all fine:

All threads were Successful!!!
Finished loop 300
Finished all loops!
Exiting App...

Any idea about to reproduce it? Probably changing some values? Attached the slightly modified test case with the creation of the "Data" class and some values.

Lvc@

Luca Garulli

unread,
Jul 18, 2012, 5:55:37 PM7/18/12
to orient-...@googlegroups.com
Hi,
please, could you run your app using this setting?

-Dfile.mmap.useOldManager=true

Lvc@

On 17 July 2012 16:02, KRP <kea...@gmail.com> wrote:
Hi Luca,

I just ran some more tests and was able to successfully run the test app I attached earlier but only when I ran it on an old Windows 7 desktop talking to a remote orientdb server running on either Windows 7 or Linux. (It didn't matter where the server lived.)

However, we get the error 100% of the time when the test app is run on Linux (either CentOS/RHEL or Mint/Ubuntu). (It doesn't matter where the server lives, either Windows 7 or Linux.)

Here is some more background
  • We run our app on CentOS (RHEL) in the cloud and the developers all run Mint Linux 13 (Ubuntu 12.04) locally.
  • We currently run with Oracle JDK 1.6_33 in all environments but we have seen this error with JDKs as old as 1.6_22.
  • We run the orientdb server as root on Linux.
  • With the test client app we've run it as both root and a normal user and in both cases it will throw the error after 2-3 minutes. (Put another way, it still fails if everything is run as root.)
  • We do run the orientdb server with the "-Dcache.level1.enabled=false" configuration so level1 cache is always disabled.
  • For the client libraries we always use the latest 1.1.0-SNAPSHOT jars from the OrientDB maven repo.
Hopefully this additional info helps. I agree with Fabrizio that the issue "feels" like a race condition.

Cheers,
KRP

--
 
 
 

KRP

unread,
Jul 18, 2012, 11:48:49 PM7/18/12
to orient-...@googlegroups.com
Hi Luca,

I ran the app 10 times with this setting and it still failed each time with the same unread response error at roughly the same time, about 2 minutes after starting the app.

I also made absolutely 100% sure that the client jars pulled into the build where the lastest snapshot build in the orientdb maven repo. And as an extra paranoid step I also set it via OGlobalConfiguration.FILE_MMAP_USE_OLD_MANAGER.setValue(Boolean.TRUE); in the code as well.

- KRP

Luca Garulli

unread,
Jul 19, 2012, 2:44:04 AM7/19/12
to orient-...@googlegroups.com

Hi,
Sorry, i didn't mention that parameter should go in the sever, not the client.

Could you retest it?
Lvc@

Sent from a touch phone: sorry for this fruit of crappy keyboard..

--
 
 
 

Andrey Lomakin

unread,
Jul 19, 2012, 5:14:16 AM7/19/12
to orient-...@googlegroups.com
Hi, I fixed problem

It is not in the mmap managers but in classes they are used by them will commit during 20 min. 


--
 
 
 



--
With best regards,
Andrey Lomakin



Andrey Lomakin

unread,
Jul 19, 2012, 5:14:51 AM7/19/12
to orient-...@googlegroups.com
wait till tests will be finished.

Luca Garulli

unread,
Jul 19, 2012, 5:41:37 AM7/19/12
to orient-...@googlegroups.com
Great!
is it the same issue of packet loss under load?

Lvc@

--
 
 
 

Andrey Lomakin

unread,
Jul 19, 2012, 5:49:07 AM7/19/12
to orient-...@googlegroups.com

Sorry, could not to reproduce the packet loss ((
Problem with data retrieval should be fixed  by SVN 6177. Could you try it ?

KRP

unread,
Jul 19, 2012, 10:27:03 AM7/19/12
to orient-...@googlegroups.com
Hi Luca and Andrey,

I finished running more tests with the test app I posted earlier and got the app to throw the same unread response in about 1-3 minutes. With the default pool size and binary read response times it takes longer to throw the error, about 20-30 minutes.

I ran these tests with an orientdb server built from r6178 and then tried with a build from r6179. (The client also used the same jars.) As an additional test I also tried setting "-Dfile.mmap.useOldManager=true" with the server but I still saw the unread response error.

- KRP

Andrey Lomakin

unread,
Jul 19, 2012, 10:46:41 AM7/19/12
to orient-...@googlegroups.com
Hi, I just changed lock policy a bit.
Could you rerun tests with latest revision. 


- KRP

--
 
 
 

KRP

unread,
Jul 19, 2012, 2:32:45 PM7/19/12
to orient-...@googlegroups.com
Hi Andrey,

Unfortunately I still get the unread response error in all my test environments.

Since you can't reproduce it in your environment I thought it might help to create one for you so I've spun up a new clean instance of CentOS 6.2 in the cloud with the test app and orientdb. It also has oracle JDK 1.6_33, svn, ant, and maven on it. I've built orientdb directly on the server from the svn trunk, installed it, and configured all the scripts to build and run the test app. It is a complete environment to build and run everything.

I just need to send the login info and credentials to you somehow. Can I send this info to in...@nuvolabase.com and Luca can forward them to you? Or is there another secure way to send this info to you?

- KRP

Andrey Lomakin

unread,
Jul 20, 2012, 4:36:41 AM7/20/12
to orient-...@googlegroups.com
From my point of view it is good idea.



- KRP

--
 
 
 

Luca Garulli

unread,
Jul 20, 2012, 5:57:11 AM7/20/12
to orient-...@googlegroups.com
Hi,
ok for me or just send that to me and andrey email addresses.

Lvc@

--
 
 
 

imikhayl

unread,
Jul 31, 2012, 12:47:29 PM7/31/12
to orient-...@googlegroups.com
Hi, I'm facing with another issue might be related to this one:
I have the following at the log:
    30.07.2012 15:48:05 com.orientechnologies.common.log.OLogManager log
[2012-07-30 15:48:05.460] http-8443-2                  System.err                                                        WARNING: Connection re-acquired transparently after 516ms and 1 retries: no errors will be thrown at application level

after that I have 99.9% of cpu usage by orientdb... it becomes very slow..(

пятница, 20 июля 2012 г., 12:57:11 UTC+3 пользователь Lvc@ написал:

Luca Garulli

unread,
Jul 31, 2012, 12:55:42 PM7/31/12
to orient-...@googlegroups.com
Hey,
is this the same message you posted 3 times ? 

Lvc@

--
 
 
 

Message has been deleted

imikhayl

unread,
Jul 31, 2012, 1:26:50 PM7/31/12
to orient-...@googlegroups.com
nor really... actually four times... it is very urgent for me.

вторник, 31 июля 2012 г., 19:55:42 UTC+3 пользователь Lvc@ написал:
Hey,
is this the same message you posted 3 times ? 

Lvc@

imikhayl

unread,
Jul 31, 2012, 1:27:43 PM7/31/12
to orient-...@googlegroups.com
do you have skype or something like that? (to discuss urgent bugs)


вторник, 31 июля 2012 г., 19:55:42 UTC+3 пользователь Lvc@ написал:
Hey,
is this the same message you posted 3 times ? 

Lvc@

Luca Garulli

unread,
Jul 31, 2012, 1:52:23 PM7/31/12
to orient-...@googlegroups.com
Hi,
the Skype connection is reserved to the subscriber of support, but you can write on this Group or email me if reserved.

Lvc@

--
 
 
 

Reply all
Reply to author
Forward
0 new messages